[PATCH 0/7] Limit console output by suppressing repetitious messages

[PATCH 0/7] Limit console output by suppressing repetitious messages

[Mike Travis]

Second version...

-- 

[PATCH 1/7] x86: Limit the number of processor bootup messages

[Mike Travis]

[-- Attachment #1: limit_boot_cpu_messages --]
[-- Type: text/plain, Size: 11494 bytes --]

With a large number of processors in a system there is an excessive amount
of messages sent to the system console.  It's estimated that with 4096
processors in a system, and the console baudrate set to 56K, the startup
messages will take about 84 minutes to clear the serial port.

This set of patches limits the number of repetitious messages which contain
no additional information.  Much of this information is obtainable from the
/proc and /sysfs.   Most of the messages are also sent to the kernel log
buffer as KERN_DEBUG messages so it can be used to examine more closely any
details specific to a processor.

The list of message transformations....

For system_state == SYSTEM_BOOTING:

[   18.669304] Booting Node   0, Processors  1 2 3 4 5 6 7 Ok.
[   19.321065] Booting Node   1, Processors  8 9 10 11 12 13 14 15 Ok.
[   20.065325] Booting Node   2, Processors  16 17 18 19 20 21 22 23 Ok.
..
[  117.153053] Booting Node  63, Processors  1016 1017 1018 1019 1020 1021 1022 1023 Ok.
[  117.952235] Brought up 1024 CPUs

Timing shows that with NO bootup messages, it takes only slightly less time
so printing adds very little overhead:

[   18.670219] Booting all processors
[  117.180248] Brought up 1024 CPUs

For Processor Information printout, the specifics of CPU0 are printed and
then at the end of the bootup sequence, a summary is printed:

[  117.957682] Processor Information for CPUS: 0-191,208-223,256-271,...
[  117.968034] Genuine Intel(R) CPU             0000 @ 2.13GHz stepping 04
[  117.977406] BogoMIPS: MIN 3989.01 (7978031) AVG 4266.62 (8533249) MAX 4537.51 (9075028)
[  117.984496] Processor Information for CPUS: 192-207,240-255,272-287,...
[  117.996032] Genuine Intel(R) CPU             0000 @ 2.13GHz stepping 03
[  118.001404] BogoMIPS: MIN 4021.49 (8042995) AVG 4265.91 (8531833) MAX 4479.79 (8959584)
[  118.012373] Processor Information for CPUS: 224-239,736-751
[  118.020032] Genuine Intel(R) CPU             0000 @ 1.87GHz stepping 03
[  118.028033] BogoMIPS: MIN 3733.92 (7467855) AVG 3746.96 (7493933) MAX 3939.52 (7879056)
[  118.036360] Processor Information for CPUS: 320-335,384-415,432-447,...
[  118.044032] Intel(R) Xeon(R) CPU           X7560  @ 2.27GHz stepping 05
[  118.053404] BogoMIPS: MIN 4244.65 (8489318) AVG 4532.45 (9064917) MAX 4666.80 (9333604)
[  118.060644] Total of 1024 processors activated (4386353.46 BogoMIPS).


The following lines have been removed:

	CPU: Physical Processor ID:
	CPU: Processor Core ID:
	CPU %d/0x%x -> Node %d

The following lines will only be printed if unusual (state):

	CPU %d is now offline  (system_state == RUNNING)

The following lines will only be printed in debug mode:

	Initializing CPU#%d

The following lines are only printed for the first cpu:

	CPU0: Hyper-Threading is disabled
	CPU0: Thermal monitoring enabled
	CPU0: <cache line sizes>


Signed-off-by: Mike Travis <travis@sgi.com>
---
 arch/x86/kernel/cpu/addon_cpuid_features.c |    6 -
 arch/x86/kernel/cpu/amd.c                  |    2 
 arch/x86/kernel/cpu/common.c               |   20 +---
 arch/x86/kernel/cpu/intel.c                |    2 
 arch/x86/kernel/cpu/intel_cacheinfo.c      |   28 +++---
 arch/x86/kernel/cpu/mcheck/therm_throt.c   |    5 -
 arch/x86/kernel/smpboot.c                  |  118 +++++++++++++++++++++++++----
 7 files changed, 129 insertions(+), 52 deletions(-)

--- linux.orig/arch/x86/kernel/cpu/addon_cpuid_features.c
+++ linux/arch/x86/kernel/cpu/addon_cpuid_features.c
@@ -127,12 +127,6 @@
 
 	c->x86_max_cores = (core_level_siblings / smp_num_siblings);
 
-
-	printk(KERN_INFO  "CPU: Physical Processor ID: %d\n",
-	       c->phys_proc_id);
-	if (c->x86_max_cores > 1)
-		printk(KERN_INFO  "CPU: Processor Core ID: %d\n",
-		       c->cpu_core_id);
 	return;
 #endif
 }
--- linux.orig/arch/x86/kernel/cpu/amd.c
+++ linux/arch/x86/kernel/cpu/amd.c
@@ -375,8 +375,6 @@
 			node = nearby_node(apicid);
 	}
 	numa_set_node(cpu, node);
-
-	printk(KERN_INFO "CPU %d/0x%x -> Node %d\n", cpu, apicid, node);
 #endif
 }
 
--- linux.orig/arch/x86/kernel/cpu/common.c
+++ linux/arch/x86/kernel/cpu/common.c
@@ -437,7 +437,7 @@
 		return;
 
 	if (cpu_has(c, X86_FEATURE_CMP_LEGACY))
-		goto out;
+		return;
 
 	if (cpu_has(c, X86_FEATURE_XTOPOLOGY))
 		return;
@@ -446,13 +446,13 @@
 
 	smp_num_siblings = (ebx & 0xff0000) >> 16;
 
-	if (smp_num_siblings == 1) {
-		printk(KERN_INFO  "CPU: Hyper-Threading is disabled\n");
-		goto out;
+	if (smp_num_siblings == 1 && c->cpu_index == 0) {
+		pr_info("CPU0: Hyper-Threading is disabled\n");
+		return;
 	}
 
 	if (smp_num_siblings <= 1)
-		goto out;
+		return;
 
 	if (smp_num_siblings > nr_cpu_ids) {
 		pr_warning("CPU: Unsupported number of siblings %d",
@@ -472,14 +472,6 @@
 
 	c->cpu_core_id = apic->phys_pkg_id(c->initial_apicid, index_msb) &
 				       ((1 << core_bits) - 1);
-
-out:
-	if ((c->x86_max_cores * smp_num_siblings) > 1) {
-		printk(KERN_INFO  "CPU: Physical Processor ID: %d\n",
-		       c->phys_proc_id);
-		printk(KERN_INFO  "CPU: Processor Core ID: %d\n",
-		       c->cpu_core_id);
-	}
 #endif
 }
 
@@ -1115,7 +1107,7 @@
 	if (cpumask_test_and_set_cpu(cpu, cpu_initialized_mask))
 		panic("CPU#%d already initialized!\n", cpu);
 
-	printk(KERN_INFO "Initializing CPU#%d\n", cpu);
+	pr_debug("Initializing CPU#%d\n", cpu);
 
 	clear_in_cr4(X86_CR4_VME|X86_CR4_PVI|X86_CR4_TSD|X86_CR4_DE);
 
--- linux.orig/arch/x86/kernel/cpu/intel.c
+++ linux/arch/x86/kernel/cpu/intel.c
@@ -266,8 +266,6 @@
 	if (node == NUMA_NO_NODE || !node_online(node))
 		node = first_node(node_online_map);
 	numa_set_node(cpu, node);
-
-	printk(KERN_INFO "CPU %d/0x%x -> Node %d\n", cpu, apicid, node);
 #endif
 }
 
--- linux.orig/arch/x86/kernel/cpu/intel_cacheinfo.c
+++ linux/arch/x86/kernel/cpu/intel_cacheinfo.c
@@ -488,21 +488,23 @@
 #endif
 	}
 
-	if (trace)
-		printk(KERN_INFO "CPU: Trace cache: %dK uops", trace);
-	else if (l1i)
-		printk(KERN_INFO "CPU: L1 I cache: %dK", l1i);
-
-	if (l1d)
-		printk(KERN_CONT ", L1 D cache: %dK\n", l1d);
-	else
-		printk(KERN_CONT "\n");
+	if (c->cpu_index == 0) {
+		if (trace)
+			pr_info("CPU0: Trace cache: %dK uops", trace);
+		else if (l1i)
+			pr_info("CPU0: L1 I cache: %dK", l1i);
+
+		if (l1d)
+			pr_cont(", L1 D cache: %dK\n", l1d);
+		else
+			pr_cont("\n");
 
-	if (l2)
-		printk(KERN_INFO "CPU: L2 cache: %dK\n", l2);
+		if (l2)
+			pr_info("CPU0: L2 cache: %dK\n", l2);
 
-	if (l3)
-		printk(KERN_INFO "CPU: L3 cache: %dK\n", l3);
+		if (l3)
+			pr_info("CPU0: L3 cache: %dK\n", l3);
+	}
 
 	c->x86_cache_size = l3 ? l3 : (l2 ? l2 : (l1i+l1d));
 
--- linux.orig/arch/x86/kernel/cpu/mcheck/therm_throt.c
+++ linux/arch/x86/kernel/cpu/mcheck/therm_throt.c
@@ -312,8 +312,9 @@
 	l = apic_read(APIC_LVTTHMR);
 	apic_write(APIC_LVTTHMR, l & ~APIC_LVT_MASKED);
 
-	printk(KERN_INFO "CPU%d: Thermal monitoring enabled (%s)\n",
-	       cpu, tm2 ? "TM2" : "TM1");
+	if (cpu == 0)
+		printk(KERN_INFO "CPU0: Thermal monitoring enabled (%s)\n",
+		       tm2 ? "TM2" : "TM1");
 
 	/* enable thermal throttle processing */
 	atomic_set(&therm_throt_en, 1);
--- linux.orig/arch/x86/kernel/smpboot.c
+++ linux/arch/x86/kernel/smpboot.c
@@ -442,6 +442,84 @@
 		return c->llc_shared_map;
 }
 
+/* Summarize Processor Information */
+static void __init summarize_cpu_info(void)
+{
+	cpumask_var_t cpulist, cpusdone;
+	int cpu;
+	int err = 0;
+
+	if (!alloc_cpumask_var(&cpulist, GFP_KERNEL))
+		err = 1;
+	else if (!alloc_cpumask_var(&cpusdone, GFP_KERNEL)) {
+		free_cpumask_var(cpulist);
+		err = 1;
+	}
+	if (err) {
+		printk(KERN_INFO "Can't print processor summaries\n");
+		return;
+	}
+
+	cpumask_clear(cpusdone);
+	for (cpu = 0; cpu < nr_cpu_ids; cpu++) {
+		struct cpuinfo_x86 *c;
+		char buf[128];
+		int ncpu, len;
+		unsigned long minlpj, maxlpj, avglpj = 0;
+
+		/* skip if cpu has already been displayed */
+		if (cpumask_test_cpu(cpu, cpusdone))
+			continue;
+
+		c = &cpu_data(cpu);
+		minlpj = ULONG_MAX;
+		maxlpj = 0;
+
+		cpumask_clear(cpulist);
+
+		/* collate all cpus with same specifics */
+		for (ncpu = cpu; ncpu < nr_cpu_ids; ncpu++) {
+			struct cpuinfo_x86 *n = &cpu_data(ncpu);
+
+			if (c->x86 != n->x86 ||
+			    c->x86_vendor != n->x86_vendor ||
+			    c->x86_model  != n->x86_model  ||
+			    c->x86_mask   != n->x86_mask   ||
+			    strcmp(c->x86_model_id, n->x86_model_id))
+				continue;
+
+			cpumask_set_cpu(ncpu, cpulist);
+			cpumask_set_cpu(ncpu, cpusdone);
+
+			if (cpu_data(ncpu).loops_per_jiffy < minlpj)
+				minlpj = cpu_data(ncpu).loops_per_jiffy;
+
+			if (cpu_data(ncpu).loops_per_jiffy > maxlpj)
+				maxlpj = cpu_data(ncpu).loops_per_jiffy;
+
+			avglpj += cpu_data(ncpu).loops_per_jiffy;
+		}
+
+		len = cpulist_scnprintf(buf, sizeof(buf), cpulist);
+		printk(KERN_INFO
+			"Processor Information for CPUS: %s%s\n",
+				buf, (len == sizeof(buf)-1) ? "..." : "");
+
+		printk(KERN_INFO);
+		print_cpu_info(c);
+
+		avglpj /= cpumask_weight(cpulist);
+		printk(KERN_INFO "BogoMIPS: MIN %lu.%02lu (%lu) "
+			"AVG %lu.%02lu (%lu) MAX %lu.%02lu (%lu)\n",
+			minlpj/(500000/HZ), (minlpj/(5000/HZ)) % 100, minlpj,
+			avglpj/(500000/HZ), (avglpj/(5000/HZ)) % 100, avglpj,
+			maxlpj/(500000/HZ), (maxlpj/(5000/HZ)) % 100, maxlpj);
+	}
+
+	free_cpumask_var(cpusdone);
+	free_cpumask_var(cpulist);
+}
+
 static void impress_friends(void)
 {
 	int cpu;
@@ -737,8 +815,21 @@
 	start_ip = setup_trampoline();
 
 	/* So we see what's up   */
-	printk(KERN_INFO "Booting processor %d APIC 0x%x ip 0x%lx\n",
-			  cpu, apicid, start_ip);
+#ifdef CONFIG_NUMA
+	if (system_state == SYSTEM_BOOTING) {
+		static int current_node = -1;
+		int node = cpu_to_node(cpu);
+
+		if (node != current_node) {
+			if (current_node > (-1))
+				pr_cont(" Ok.\n");
+			current_node = node;
+			pr_info("Booting Node %3d, Processors ", node);
+		}
+		pr_cont(" %d%s", cpu, cpu == (nr_cpu_ids - 1) ? " Ok.\n" : "");
+	} else
+#endif
+		pr_info("Booting Processor %d APIC 0x%x\n", cpu, apicid);
 
 	/*
 	 * This grunge runs the startup process for
@@ -787,21 +878,17 @@
 			udelay(100);
 		}
 
-		if (cpumask_test_cpu(cpu, cpu_callin_mask)) {
-			/* number CPUs logically, starting from 1 (BSP is 0) */
-			pr_debug("OK.\n");
-			printk(KERN_INFO "CPU%d: ", cpu);
-			print_cpu_info(&cpu_data(cpu));
-			pr_debug("CPU has booted.\n");
-		} else {
+		if (cpumask_test_cpu(cpu, cpu_callin_mask))
+			pr_debug("CPU%d: has booted.\n", cpu);
+		else {
 			boot_error = 1;
 			if (*((volatile unsigned char *)trampoline_base)
 					== 0xA5)
 				/* trampoline started but...? */
-				printk(KERN_ERR "Stuck ??\n");
+				pr_err("CPU%d: Stuck ??\n", cpu);
 			else
 				/* trampoline code not run */
-				printk(KERN_ERR "Not responding.\n");
+				pr_err("CPU%d: Not responding.\n", cpu);
 			if (apic->inquire_remote_apic)
 				apic->inquire_remote_apic(apicid);
 		}
@@ -1147,6 +1234,9 @@
 {
 	pr_debug("Boot done.\n");
 
+	/* print processor data summaries */
+	summarize_cpu_info();
+
 	impress_friends();
 #ifdef CONFIG_X86_IO_APIC
 	setup_ioapic_dest();
@@ -1300,14 +1390,16 @@
 	for (i = 0; i < 10; i++) {
 		/* They ack this in play_dead by setting CPU_DEAD */
 		if (per_cpu(cpu_state, cpu) == CPU_DEAD) {
-			printk(KERN_INFO "CPU %d is now offline\n", cpu);
+			if (system_state == SYSTEM_RUNNING)
+				pr_info("CPU %u is now offline\n", cpu);
+
 			if (1 == num_online_cpus())
 				alternatives_smp_switch(0);
 			return;
 		}
 		msleep(100);
 	}
-	printk(KERN_ERR "CPU %u didn't die...\n", cpu);
+	pr_err("CPU %u didn't die...\n", cpu);
 }
 
 void play_dead_common(void)

-- 

Re: [PATCH 1/7] x86: Limit the number of processor bootup messages

[Ingo Molnar]

* Mike Travis <travis@sgi.com> wrote:

> --- linux.orig/arch/x86/kernel/smpboot.c
> +++ linux/arch/x86/kernel/smpboot.c
> @@ -442,6 +442,84 @@
>  		return c->llc_shared_map;
>  }
>  
> +/* Summarize Processor Information */
> +static void __init summarize_cpu_info(void)
> +{
> +	cpumask_var_t cpulist, cpusdone;
> +	int cpu;
> +	int err = 0;
> +
> +	if (!alloc_cpumask_var(&cpulist, GFP_KERNEL))
> +		err = 1;
> +	else if (!alloc_cpumask_var(&cpusdone, GFP_KERNEL)) {
> +		free_cpumask_var(cpulist);
> +		err = 1;
> +	}
> +	if (err) {
> +		printk(KERN_INFO "Can't print processor summaries\n");
> +		return;
> +	}
> +
> +	cpumask_clear(cpusdone);
> +	for (cpu = 0; cpu < nr_cpu_ids; cpu++) {
> +		struct cpuinfo_x86 *c;
> +		char buf[128];
> +		int ncpu, len;
> +		unsigned long minlpj, maxlpj, avglpj = 0;
> +
> +		/* skip if cpu has already been displayed */
> +		if (cpumask_test_cpu(cpu, cpusdone))
> +			continue;
> +
> +		c = &cpu_data(cpu);
> +		minlpj = ULONG_MAX;
> +		maxlpj = 0;
> +
> +		cpumask_clear(cpulist);
> +
> +		/* collate all cpus with same specifics */
> +		for (ncpu = cpu; ncpu < nr_cpu_ids; ncpu++) {
> +			struct cpuinfo_x86 *n = &cpu_data(ncpu);
> +
> +			if (c->x86 != n->x86 ||
> +			    c->x86_vendor != n->x86_vendor ||
> +			    c->x86_model  != n->x86_model  ||
> +			    c->x86_mask   != n->x86_mask   ||
> +			    strcmp(c->x86_model_id, n->x86_model_id))
> +				continue;
> +
> +			cpumask_set_cpu(ncpu, cpulist);
> +			cpumask_set_cpu(ncpu, cpusdone);
> +
> +			if (cpu_data(ncpu).loops_per_jiffy < minlpj)
> +				minlpj = cpu_data(ncpu).loops_per_jiffy;
> +
> +			if (cpu_data(ncpu).loops_per_jiffy > maxlpj)
> +				maxlpj = cpu_data(ncpu).loops_per_jiffy;
> +
> +			avglpj += cpu_data(ncpu).loops_per_jiffy;
> +		}
> +
> +		len = cpulist_scnprintf(buf, sizeof(buf), cpulist);
> +		printk(KERN_INFO
> +			"Processor Information for CPUS: %s%s\n",
> +				buf, (len == sizeof(buf)-1) ? "..." : "");
> +
> +		printk(KERN_INFO);
> +		print_cpu_info(c);
> +
> +		avglpj /= cpumask_weight(cpulist);
> +		printk(KERN_INFO "BogoMIPS: MIN %lu.%02lu (%lu) "
> +			"AVG %lu.%02lu (%lu) MAX %lu.%02lu (%lu)\n",
> +			minlpj/(500000/HZ), (minlpj/(5000/HZ)) % 100, minlpj,
> +			avglpj/(500000/HZ), (avglpj/(5000/HZ)) % 100, avglpj,
> +			maxlpj/(500000/HZ), (maxlpj/(5000/HZ)) % 100, maxlpj);
> +	}
> +
> +	free_cpumask_var(cpusdone);
> +	free_cpumask_var(cpulist);
> +}
> +

Sigh, that's _way_ too complex.

If you cannot print it in a summarized way without carrying over stupid 
state like bitmaps then please do the simple and obvious, and print:

booting CPUs: #0 #1 #2 #3 #4 #5 #6 ...

It's a really long line with 4096 CPUs but that's not a big problem - on 
most systems it will look sane.

	Ingo

Re: [PATCH 1/7] x86: Limit the number of processor bootup messages

[Mike Travis]

Ingo Molnar wrote:
> * Mike Travis <travis@sgi.com> wrote:
> 
>> --- linux.orig/arch/x86/kernel/smpboot.c
>> +++ linux/arch/x86/kernel/smpboot.c
>> @@ -442,6 +442,84 @@
>>  		return c->llc_shared_map;
>>  }
>>  
>> +/* Summarize Processor Information */
>> +static void __init summarize_cpu_info(void)
>> +{
>> +	cpumask_var_t cpulist, cpusdone;
>> +	int cpu;
>> +	int err = 0;
>> +
>> +	if (!alloc_cpumask_var(&cpulist, GFP_KERNEL))
>> +		err = 1;
>> +	else if (!alloc_cpumask_var(&cpusdone, GFP_KERNEL)) {
>> +		free_cpumask_var(cpulist);
>> +		err = 1;
>> +	}
>> +	if (err) {
>> +		printk(KERN_INFO "Can't print processor summaries\n");
>> +		return;
>> +	}
>> +
>> +	cpumask_clear(cpusdone);
>> +	for (cpu = 0; cpu < nr_cpu_ids; cpu++) {
>> +		struct cpuinfo_x86 *c;
>> +		char buf[128];
>> +		int ncpu, len;
>> +		unsigned long minlpj, maxlpj, avglpj = 0;
>> +
>> +		/* skip if cpu has already been displayed */
>> +		if (cpumask_test_cpu(cpu, cpusdone))
>> +			continue;
>> +
>> +		c = &cpu_data(cpu);
>> +		minlpj = ULONG_MAX;
>> +		maxlpj = 0;
>> +
>> +		cpumask_clear(cpulist);
>> +
>> +		/* collate all cpus with same specifics */
>> +		for (ncpu = cpu; ncpu < nr_cpu_ids; ncpu++) {
>> +			struct cpuinfo_x86 *n = &cpu_data(ncpu);
>> +
>> +			if (c->x86 != n->x86 ||
>> +			    c->x86_vendor != n->x86_vendor ||
>> +			    c->x86_model  != n->x86_model  ||
>> +			    c->x86_mask   != n->x86_mask   ||
>> +			    strcmp(c->x86_model_id, n->x86_model_id))
>> +				continue;
>> +
>> +			cpumask_set_cpu(ncpu, cpulist);
>> +			cpumask_set_cpu(ncpu, cpusdone);
>> +
>> +			if (cpu_data(ncpu).loops_per_jiffy < minlpj)
>> +				minlpj = cpu_data(ncpu).loops_per_jiffy;
>> +
>> +			if (cpu_data(ncpu).loops_per_jiffy > maxlpj)
>> +				maxlpj = cpu_data(ncpu).loops_per_jiffy;
>> +
>> +			avglpj += cpu_data(ncpu).loops_per_jiffy;
>> +		}
>> +
>> +		len = cpulist_scnprintf(buf, sizeof(buf), cpulist);
>> +		printk(KERN_INFO
>> +			"Processor Information for CPUS: %s%s\n",
>> +				buf, (len == sizeof(buf)-1) ? "..." : "");
>> +
>> +		printk(KERN_INFO);
>> +		print_cpu_info(c);
>> +
>> +		avglpj /= cpumask_weight(cpulist);
>> +		printk(KERN_INFO "BogoMIPS: MIN %lu.%02lu (%lu) "
>> +			"AVG %lu.%02lu (%lu) MAX %lu.%02lu (%lu)\n",
>> +			minlpj/(500000/HZ), (minlpj/(5000/HZ)) % 100, minlpj,
>> +			avglpj/(500000/HZ), (avglpj/(5000/HZ)) % 100, avglpj,
>> +			maxlpj/(500000/HZ), (maxlpj/(5000/HZ)) % 100, maxlpj);
>> +	}
>> +
>> +	free_cpumask_var(cpusdone);
>> +	free_cpumask_var(cpulist);
>> +}
>> +
> 
> Sigh, that's _way_ too complex.
> 
> If you cannot print it in a summarized way without carrying over stupid 
> state like bitmaps then please do the simple and obvious, and print:
> 
> booting CPUs: #0 #1 #2 #3 #4 #5 #6 ...

That is almost exactly what it does.  The following function prints
each cpu # as they are being booted, so you see a progressive listing.

Booting Node   0, Processors  1 2 3 4 5 6 7 Ok.
Booting Node   1, Processors  8 9 10 11 12 13 14 15 Ok.
Booting Node   2, Processors  16 17 18 19 20 21 22 23 Ok.

+#ifdef CONFIG_NUMA
+	if (system_state == SYSTEM_BOOTING) {
+		static int current_node = -1;
+		int node = cpu_to_node(cpu);
+
+		if (node != current_node) {
+			if (current_node > (-1))
+				pr_cont(" Ok.\n");
+			current_node = node;
+			pr_info("Booting Node %3d, Processors ", node);
+		}
+		pr_cont(" %d%s", cpu, cpu == (nr_cpu_ids - 1) ? " Ok.\n" : "");
+	} else
+#endif
+		pr_info("Booting Processor %d APIC 0x%x\n", cpu, apicid);

The part you highlight above is to print the summary shown below of the cpus
in the system after they have been booted, and since it's an init function,
it will be removed.

Processor Information for CPUS: 0-191,208-223,256-271,...
Genuine Intel(R) CPU             0000 @ 2.13GHz stepping 04
BogoMIPS: MIN 3989.01 (7978031) AVG 4266.62 (8533249) MAX 4537.51 (9075028)
Processor Information for CPUS: 192-207,240-255,272-287,...
Genuine Intel(R) CPU             0000 @ 2.13GHz stepping 03
BogoMIPS: MIN 4021.49 (8042995) AVG 4265.91 (8531833) MAX 4479.79 (8959584)

> It's a really long line with 4096 CPUs but that's not a big problem - on 
> most systems it will look sane.
> 
> 	Ingo

Re: [PATCH 1/7] x86: Limit the number of processor bootup messages

[Ingo Molnar]

* Mike Travis <travis@sgi.com> wrote:

> 
> 
> Ingo Molnar wrote:
> >* Mike Travis <travis@sgi.com> wrote:
> >
> >>--- linux.orig/arch/x86/kernel/smpboot.c
> >>+++ linux/arch/x86/kernel/smpboot.c
> >>@@ -442,6 +442,84 @@
> >> 		return c->llc_shared_map;
> >> }
> >>+/* Summarize Processor Information */
> >>+static void __init summarize_cpu_info(void)
> >>+{
> >>+	cpumask_var_t cpulist, cpusdone;
> >>+	int cpu;
> >>+	int err = 0;
> >>+
> >>+	if (!alloc_cpumask_var(&cpulist, GFP_KERNEL))
> >>+		err = 1;
> >>+	else if (!alloc_cpumask_var(&cpusdone, GFP_KERNEL)) {
> >>+		free_cpumask_var(cpulist);
> >>+		err = 1;
> >>+	}
> >>+	if (err) {
> >>+		printk(KERN_INFO "Can't print processor summaries\n");
> >>+		return;
> >>+	}
> >>+
> >>+	cpumask_clear(cpusdone);
> >>+	for (cpu = 0; cpu < nr_cpu_ids; cpu++) {
> >>+		struct cpuinfo_x86 *c;
> >>+		char buf[128];
> >>+		int ncpu, len;
> >>+		unsigned long minlpj, maxlpj, avglpj = 0;
> >>+
> >>+		/* skip if cpu has already been displayed */
> >>+		if (cpumask_test_cpu(cpu, cpusdone))
> >>+			continue;
> >>+
> >>+		c = &cpu_data(cpu);
> >>+		minlpj = ULONG_MAX;
> >>+		maxlpj = 0;
> >>+
> >>+		cpumask_clear(cpulist);
> >>+
> >>+		/* collate all cpus with same specifics */
> >>+		for (ncpu = cpu; ncpu < nr_cpu_ids; ncpu++) {
> >>+			struct cpuinfo_x86 *n = &cpu_data(ncpu);
> >>+
> >>+			if (c->x86 != n->x86 ||
> >>+			    c->x86_vendor != n->x86_vendor ||
> >>+			    c->x86_model  != n->x86_model  ||
> >>+			    c->x86_mask   != n->x86_mask   ||
> >>+			    strcmp(c->x86_model_id, n->x86_model_id))
> >>+				continue;
> >>+
> >>+			cpumask_set_cpu(ncpu, cpulist);
> >>+			cpumask_set_cpu(ncpu, cpusdone);
> >>+
> >>+			if (cpu_data(ncpu).loops_per_jiffy < minlpj)
> >>+				minlpj = cpu_data(ncpu).loops_per_jiffy;
> >>+
> >>+			if (cpu_data(ncpu).loops_per_jiffy > maxlpj)
> >>+				maxlpj = cpu_data(ncpu).loops_per_jiffy;
> >>+
> >>+			avglpj += cpu_data(ncpu).loops_per_jiffy;
> >>+		}
> >>+
> >>+		len = cpulist_scnprintf(buf, sizeof(buf), cpulist);
> >>+		printk(KERN_INFO
> >>+			"Processor Information for CPUS: %s%s\n",
> >>+				buf, (len == sizeof(buf)-1) ? "..." : "");
> >>+
> >>+		printk(KERN_INFO);
> >>+		print_cpu_info(c);
> >>+
> >>+		avglpj /= cpumask_weight(cpulist);
> >>+		printk(KERN_INFO "BogoMIPS: MIN %lu.%02lu (%lu) "
> >>+			"AVG %lu.%02lu (%lu) MAX %lu.%02lu (%lu)\n",
> >>+			minlpj/(500000/HZ), (minlpj/(5000/HZ)) % 100, minlpj,
> >>+			avglpj/(500000/HZ), (avglpj/(5000/HZ)) % 100, avglpj,
> >>+			maxlpj/(500000/HZ), (maxlpj/(5000/HZ)) % 100, maxlpj);
> >>+	}
> >>+
> >>+	free_cpumask_var(cpusdone);
> >>+	free_cpumask_var(cpulist);
> >>+}
> >>+
> >
> >Sigh, that's _way_ too complex.
> >
> >If you cannot print it in a summarized way without carrying over
> >stupid state like bitmaps then please do the simple and obvious,
> >and print:
> >
> >booting CPUs: #0 #1 #2 #3 #4 #5 #6 ...
> 
> That is almost exactly what it does. [...]

You are missing my point i think, which is that we dont want the 76 
lines long summarize_cpu_info() complexity during bootup. Lets keep it 
_very_ simple and zap excessive messages - like DaveJ's patch did.

	Ingo

Re: [PATCH 1/7] x86: Limit the number of processor bootup messages

[Mike Travis]

Ingo Molnar wrote:
> * Mike Travis <travis@sgi.com> wrote:
> 
>>
>> Ingo Molnar wrote:
>>> * Mike Travis <travis@sgi.com> wrote:
>>>
>>>> --- linux.orig/arch/x86/kernel/smpboot.c
>>>> +++ linux/arch/x86/kernel/smpboot.c
>>>> @@ -442,6 +442,84 @@
>>>> 		return c->llc_shared_map;
>>>> }
>>>> +/* Summarize Processor Information */
>>>> +static void __init summarize_cpu_info(void)
>>>> +{
>>>> +	cpumask_var_t cpulist, cpusdone;
>>>> +	int cpu;
>>>> +	int err = 0;
>>>> +
>>>> +	if (!alloc_cpumask_var(&cpulist, GFP_KERNEL))
>>>> +		err = 1;
>>>> +	else if (!alloc_cpumask_var(&cpusdone, GFP_KERNEL)) {
>>>> +		free_cpumask_var(cpulist);
>>>> +		err = 1;
>>>> +	}
>>>> +	if (err) {
>>>> +		printk(KERN_INFO "Can't print processor summaries\n");
>>>> +		return;
>>>> +	}
>>>> +
>>>> +	cpumask_clear(cpusdone);
>>>> +	for (cpu = 0; cpu < nr_cpu_ids; cpu++) {
>>>> +		struct cpuinfo_x86 *c;
>>>> +		char buf[128];
>>>> +		int ncpu, len;
>>>> +		unsigned long minlpj, maxlpj, avglpj = 0;
>>>> +
>>>> +		/* skip if cpu has already been displayed */
>>>> +		if (cpumask_test_cpu(cpu, cpusdone))
>>>> +			continue;
>>>> +
>>>> +		c = &cpu_data(cpu);
>>>> +		minlpj = ULONG_MAX;
>>>> +		maxlpj = 0;
>>>> +
>>>> +		cpumask_clear(cpulist);
>>>> +
>>>> +		/* collate all cpus with same specifics */
>>>> +		for (ncpu = cpu; ncpu < nr_cpu_ids; ncpu++) {
>>>> +			struct cpuinfo_x86 *n = &cpu_data(ncpu);
>>>> +
>>>> +			if (c->x86 != n->x86 ||
>>>> +			    c->x86_vendor != n->x86_vendor ||
>>>> +			    c->x86_model  != n->x86_model  ||
>>>> +			    c->x86_mask   != n->x86_mask   ||
>>>> +			    strcmp(c->x86_model_id, n->x86_model_id))
>>>> +				continue;
>>>> +
>>>> +			cpumask_set_cpu(ncpu, cpulist);
>>>> +			cpumask_set_cpu(ncpu, cpusdone);
>>>> +
>>>> +			if (cpu_data(ncpu).loops_per_jiffy < minlpj)
>>>> +				minlpj = cpu_data(ncpu).loops_per_jiffy;
>>>> +
>>>> +			if (cpu_data(ncpu).loops_per_jiffy > maxlpj)
>>>> +				maxlpj = cpu_data(ncpu).loops_per_jiffy;
>>>> +
>>>> +			avglpj += cpu_data(ncpu).loops_per_jiffy;
>>>> +		}
>>>> +
>>>> +		len = cpulist_scnprintf(buf, sizeof(buf), cpulist);
>>>> +		printk(KERN_INFO
>>>> +			"Processor Information for CPUS: %s%s\n",
>>>> +				buf, (len == sizeof(buf)-1) ? "..." : "");
>>>> +
>>>> +		printk(KERN_INFO);
>>>> +		print_cpu_info(c);
>>>> +
>>>> +		avglpj /= cpumask_weight(cpulist);
>>>> +		printk(KERN_INFO "BogoMIPS: MIN %lu.%02lu (%lu) "
>>>> +			"AVG %lu.%02lu (%lu) MAX %lu.%02lu (%lu)\n",
>>>> +			minlpj/(500000/HZ), (minlpj/(5000/HZ)) % 100, minlpj,
>>>> +			avglpj/(500000/HZ), (avglpj/(5000/HZ)) % 100, avglpj,
>>>> +			maxlpj/(500000/HZ), (maxlpj/(5000/HZ)) % 100, maxlpj);
>>>> +	}
>>>> +
>>>> +	free_cpumask_var(cpusdone);
>>>> +	free_cpumask_var(cpulist);
>>>> +}
>>>> +
>>> Sigh, that's _way_ too complex.
>>>
>>> If you cannot print it in a summarized way without carrying over
>>> stupid state like bitmaps then please do the simple and obvious,
>>> and print:
>>>
>>> booting CPUs: #0 #1 #2 #3 #4 #5 #6 ...
>> That is almost exactly what it does. [...]
> 
> You are missing my point i think, which is that we dont want the 76 
> lines long summarize_cpu_info() complexity during bootup. Lets keep it 
> _very_ simple and zap excessive messages - like DaveJ's patch did.
> 
> 	Ingo

Ok, I'll zap the summary as I'm not sure how much easier to make a function
that scans the cpus to find ones that are common, and print their specific
information.  If I can include the model id and stepping in some /proc
interface, then a user app could do the same thing (though I'm not sure if
BogoMIPs is available or not.)

Btw, I don't actually see the difference between the two functions, both
scan a bit map list (apics vs. cpus) to find unprocessed items, then
collates similar items comparing (nodeid vs. cpu specifics) and then
prints a summary using the scnlistprintf to gather progressive item #'s.
But maybe I'm missing something.

Thanks,
Mike

Re: [PATCH 1/7] x86: Limit the number of processor bootup messages

[Yinghai Lu]

On Thu, Nov 12, 2009 at 9:19 AM, Mike Travis <travis@sgi.com> wrote:
> With a large number of processors in a system there is an excessive amount
> of messages sent to the system console.  It's estimated that with 4096
> processors in a system, and the console baudrate set to 56K, the startup
> messages will take about 84 minutes to clear the serial port.
>
> This set of patches limits the number of repetitious messages which contain
> no additional information.  Much of this information is obtainable from the
> /proc and /sysfs.   Most of the messages are also sent to the kernel log
> buffer as KERN_DEBUG messages so it can be used to examine more closely any
> details specific to a processor.
>
> The list of message transformations....
>
> For system_state == SYSTEM_BOOTING:
>
> [   18.669304] Booting Node   0, Processors  1 2 3 4 5 6 7 Ok.
> [   19.321065] Booting Node   1, Processors  8 9 10 11 12 13 14 15 Ok.
> [   20.065325] Booting Node   2, Processors  16 17 18 19 20 21 22 23 Ok.
> ..
> [  117.153053] Booting Node  63, Processors  1016 1017 1018 1019 1020 1021 1022 1023 Ok.
> [  117.952235] Brought up 1024 CPUs
>
> Timing shows that with NO bootup messages, it takes only slightly less time
> so printing adds very little overhead:
>
> [   18.670219] Booting all processors
> [  117.180248] Brought up 1024 CPUs
>
> For Processor Information printout, the specifics of CPU0 are printed and
> then at the end of the bootup sequence, a summary is printed:
>
> [  117.957682] Processor Information for CPUS: 0-191,208-223,256-271,...
> [  117.968034] Genuine Intel(R) CPU             0000 @ 2.13GHz stepping 04
> [  117.977406] BogoMIPS: MIN 3989.01 (7978031) AVG 4266.62 (8533249) MAX 4537.51 (9075028)
> [  117.984496] Processor Information for CPUS: 192-207,240-255,272-287,...
> [  117.996032] Genuine Intel(R) CPU             0000 @ 2.13GHz stepping 03
> [  118.001404] BogoMIPS: MIN 4021.49 (8042995) AVG 4265.91 (8531833) MAX 4479.79 (8959584)
> [  118.012373] Processor Information for CPUS: 224-239,736-751
> [  118.020032] Genuine Intel(R) CPU             0000 @ 1.87GHz stepping 03
> [  118.028033] BogoMIPS: MIN 3733.92 (7467855) AVG 3746.96 (7493933) MAX 3939.52 (7879056)
> [  118.036360] Processor Information for CPUS: 320-335,384-415,432-447,...
> [  118.044032] Intel(R) Xeon(R) CPU           X7560  @ 2.27GHz stepping 05
> [  118.053404] BogoMIPS: MIN 4244.65 (8489318) AVG 4532.45 (9064917) MAX 4666.80 (9333604)
> [  118.060644] Total of 1024 processors activated (4386353.46 BogoMIPS).
>
>
> The following lines have been removed:
>
>        CPU: Physical Processor ID:
>        CPU: Processor Core ID:
>        CPU %d/0x%x -> Node %d

why?

Re: [PATCH 1/7] x86: Limit the number of processor bootup messages

[Mike Travis]

Yinghai Lu wrote:
> On Thu, Nov 12, 2009 at 9:19 AM, Mike Travis <travis@sgi.com> wrote:
>> With a large number of processors in a system there is an excessive amount
>> of messages sent to the system console.  It's estimated that with 4096
>> processors in a system, and the console baudrate set to 56K, the startup
>> messages will take about 84 minutes to clear the serial port.
>>
>> This set of patches limits the number of repetitious messages which contain
>> no additional information.  Much of this information is obtainable from the
>> /proc and /sysfs.   Most of the messages are also sent to the kernel log
>> buffer as KERN_DEBUG messages so it can be used to examine more closely any
>> details specific to a processor.
>>
>> The list of message transformations....
>>
>> For system_state == SYSTEM_BOOTING:
>>
>> [   18.669304] Booting Node   0, Processors  1 2 3 4 5 6 7 Ok.
>> [   19.321065] Booting Node   1, Processors  8 9 10 11 12 13 14 15 Ok.
>> [   20.065325] Booting Node   2, Processors  16 17 18 19 20 21 22 23 Ok.
>> ..
>> [  117.153053] Booting Node  63, Processors  1016 1017 1018 1019 1020 1021 1022 1023 Ok.
>> [  117.952235] Brought up 1024 CPUs
>>
>> Timing shows that with NO bootup messages, it takes only slightly less time
>> so printing adds very little overhead:
>>
>> [   18.670219] Booting all processors
>> [  117.180248] Brought up 1024 CPUs
>>
>> For Processor Information printout, the specifics of CPU0 are printed and
>> then at the end of the bootup sequence, a summary is printed:
>>
>> [  117.957682] Processor Information for CPUS: 0-191,208-223,256-271,...
>> [  117.968034] Genuine Intel(R) CPU             0000 @ 2.13GHz stepping 04
>> [  117.977406] BogoMIPS: MIN 3989.01 (7978031) AVG 4266.62 (8533249) MAX 4537.51 (9075028)
>> [  117.984496] Processor Information for CPUS: 192-207,240-255,272-287,...
>> [  117.996032] Genuine Intel(R) CPU             0000 @ 2.13GHz stepping 03
>> [  118.001404] BogoMIPS: MIN 4021.49 (8042995) AVG 4265.91 (8531833) MAX 4479.79 (8959584)
>> [  118.012373] Processor Information for CPUS: 224-239,736-751
>> [  118.020032] Genuine Intel(R) CPU             0000 @ 1.87GHz stepping 03
>> [  118.028033] BogoMIPS: MIN 3733.92 (7467855) AVG 3746.96 (7493933) MAX 3939.52 (7879056)
>> [  118.036360] Processor Information for CPUS: 320-335,384-415,432-447,...
>> [  118.044032] Intel(R) Xeon(R) CPU           X7560  @ 2.27GHz stepping 05
>> [  118.053404] BogoMIPS: MIN 4244.65 (8489318) AVG 4532.45 (9064917) MAX 4666.80 (9333604)
>> [  118.060644] Total of 1024 processors activated (4386353.46 BogoMIPS).
>>
>>
>> The following lines have been removed:
>>
>>        CPU: Physical Processor ID:
>>        CPU: Processor Core ID:
>>        CPU %d/0x%x -> Node %d
> 
> why?

Someone asked that they be removed?

The intent of the patch was to remove repetitious per cpu printouts where the
information is easily available via some other means, which is the case of the
above 3 lines.  Would you prefer they stay as KERN_DEBUG or pr_debug lines?
(I had it this way in the first version but then was told that the messages were
not needed.)

Thanks,
Mike

Re: [PATCH 1/7] x86: Limit the number of processor bootup messages

[Yinghai Lu]

On Fri, Nov 13, 2009 at 5:46 AM, Mike Travis <travis@sgi.com> wrote:
>
>
> Yinghai Lu wrote:
>>
>> On Thu, Nov 12, 2009 at 9:19 AM, Mike Travis <travis@sgi.com> wrote:
>>>
>>> With a large number of processors in a system there is an excessive
>>> amount
>>> of messages sent to the system console.  It's estimated that with 4096
>>> processors in a system, and the console baudrate set to 56K, the startup
>>> messages will take about 84 minutes to clear the serial port.
>>>
>>> This set of patches limits the number of repetitious messages which
>>> contain
>>> no additional information.  Much of this information is obtainable from
>>> the
>>> /proc and /sysfs.   Most of the messages are also sent to the kernel log
>>> buffer as KERN_DEBUG messages so it can be used to examine more closely
>>> any
>>> details specific to a processor.
>>>
>>> The list of message transformations....
>>>
>>> For system_state == SYSTEM_BOOTING:
>>>
>>> [   18.669304] Booting Node   0, Processors  1 2 3 4 5 6 7 Ok.
>>> [   19.321065] Booting Node   1, Processors  8 9 10 11 12 13 14 15 Ok.
>>> [   20.065325] Booting Node   2, Processors  16 17 18 19 20 21 22 23 Ok.
>>> ..
>>> [  117.153053] Booting Node  63, Processors  1016 1017 1018 1019 1020
>>> 1021 1022 1023 Ok.
>>> [  117.952235] Brought up 1024 CPUs
>>>
>>> Timing shows that with NO bootup messages, it takes only slightly less
>>> time
>>> so printing adds very little overhead:
>>>
>>> [   18.670219] Booting all processors
>>> [  117.180248] Brought up 1024 CPUs
>>>
>>> For Processor Information printout, the specifics of CPU0 are printed and
>>> then at the end of the bootup sequence, a summary is printed:
>>>
>>> [  117.957682] Processor Information for CPUS: 0-191,208-223,256-271,...
>>> [  117.968034] Genuine Intel(R) CPU             0000 @ 2.13GHz stepping
>>> 04
>>> [  117.977406] BogoMIPS: MIN 3989.01 (7978031) AVG 4266.62 (8533249) MAX
>>> 4537.51 (9075028)
>>> [  117.984496] Processor Information for CPUS:
>>> 192-207,240-255,272-287,...
>>> [  117.996032] Genuine Intel(R) CPU             0000 @ 2.13GHz stepping
>>> 03
>>> [  118.001404] BogoMIPS: MIN 4021.49 (8042995) AVG 4265.91 (8531833) MAX
>>> 4479.79 (8959584)
>>> [  118.012373] Processor Information for CPUS: 224-239,736-751
>>> [  118.020032] Genuine Intel(R) CPU             0000 @ 1.87GHz stepping
>>> 03
>>> [  118.028033] BogoMIPS: MIN 3733.92 (7467855) AVG 3746.96 (7493933) MAX
>>> 3939.52 (7879056)
>>> [  118.036360] Processor Information for CPUS:
>>> 320-335,384-415,432-447,...
>>> [  118.044032] Intel(R) Xeon(R) CPU           X7560  @ 2.27GHz stepping
>>> 05
>>> [  118.053404] BogoMIPS: MIN 4244.65 (8489318) AVG 4532.45 (9064917) MAX
>>> 4666.80 (9333604)
>>> [  118.060644] Total of 1024 processors activated (4386353.46 BogoMIPS).
>>>
>>>
>>> The following lines have been removed:
>>>
>>>       CPU: Physical Processor ID:
>>>       CPU: Processor Core ID:
>>>       CPU %d/0x%x -> Node %d
>>
>> why?
>
> Someone asked that they be removed?
>
> The intent of the patch was to remove repetitious per cpu printouts where
> the
> information is easily available via some other means, which is the case of
> the
> above 3 lines.  Would you prefer they stay as KERN_DEBUG or pr_debug lines?
> (I had it this way in the first version but then was told that the messages
> were
> not needed.)

at least on one distribution kernel ( SLES 11?), when BSP is from
socket1, the kernel is not happy
(thought that cpu is from socket 0).

YH

[PATCH 2/7] ACPI: Limit the number of per cpu ACPI bootup messages

[Mike Travis]

[-- Attachment #1: limit_acpi_boot_messages --]
[-- Type: text/plain, Size: 2456 bytes --]

Limit the number of per cpu ACPI messages when system is booting to
prevent clogging up the console output with repetitious messages.

Signed-off-by: Mike Travis <travis@sgi.com>
---
 drivers/acpi/fan.c            |    2 +-
 drivers/acpi/processor_core.c |    2 +-
 drivers/acpi/tables.c         |   28 +++++++++++++++++++---------
 3 files changed, 21 insertions(+), 11 deletions(-)

--- linux.orig/drivers/acpi/fan.c
+++ linux/drivers/acpi/fan.c
@@ -267,7 +267,7 @@
 		goto end;
 	}
 
-	dev_info(&device->dev, "registered as cooling_device%d\n", cdev->id);
+	dev_dbg(&device->dev, "registered as cooling_device%d\n", cdev->id);
 
 	device->driver_data = cdev;
 	result = sysfs_create_link(&device->dev.kobj,
--- linux.orig/drivers/acpi/processor_core.c
+++ linux/drivers/acpi/processor_core.c
@@ -845,7 +845,7 @@
 		goto err_power_exit;
 	}
 
-	dev_info(&device->dev, "registered as cooling_device%d\n",
+	dev_dbg(&device->dev, "registered as cooling_device%d\n",
 		 pr->cdev->id);
 
 	result = sysfs_create_link(&device->dev.kobj,
--- linux.orig/drivers/acpi/tables.c
+++ linux/drivers/acpi/tables.c
@@ -66,11 +66,15 @@
 		{
 			struct acpi_madt_local_x2apic *p =
 			    (struct acpi_madt_local_x2apic *)header;
-			printk(KERN_INFO PREFIX
-			       "X2APIC (apic_id[0x%02x] uid[0x%02x] %s)\n",
-			       p->local_apic_id, p->uid,
-			       (p->lapic_flags & ACPI_MADT_ENABLED) ?
-			       "enabled" : "disabled");
+			/*
+			 * Per cpu tracing clogs console output when NR_CPUS
+			 * is large.  Send only to kernel log buffer.
+			 */
+			printk(KERN_DEBUG PREFIX
+				"X2APIC (apic_id[0x%02x] uid[0x%02x] %s)\n",
+				p->local_apic_id, p->uid,
+				(p->lapic_flags & ACPI_MADT_ENABLED) ?
+					"enabled" : "disabled");
 		}
 		break;
 
@@ -171,10 +175,16 @@
 		{
 			struct acpi_madt_local_sapic *p =
 			    (struct acpi_madt_local_sapic *)header;
-			printk(KERN_INFO PREFIX
-			       "LSAPIC (acpi_id[0x%02x] lsapic_id[0x%02x] lsapic_eid[0x%02x] %s)\n",
-			       p->processor_id, p->id, p->eid,
-			       (p->lapic_flags & ACPI_MADT_ENABLED) ? "enabled" : "disabled");
+			/*
+			 * Per cpu tracing clogs console output when NR_CPUS
+			 * is large.  Send only to kernel log buffer.
+			 */
+			printk(KERN_DEBUG PREFIX
+				"LSAPIC (acpi_id[0x%02x] lsapic_id[0x%02x] "
+				"lsapic_eid[0x%02x] %s)\n",
+				p->processor_id, p->id, p->eid,
+				(p->lapic_flags & ACPI_MADT_ENABLED) ?
+					"enabled" : "disabled");
 		}
 		break;
 

-- 

Re: [PATCH 2/7] ACPI: Limit the number of per cpu ACPI bootup messages

[David Rientjes]

On Thu, 12 Nov 2009, Mike Travis wrote:

> Limit the number of per cpu ACPI messages when system is booting to
> prevent clogging up the console output with repetitious messages.
> 

... "by changing the log level from KERN_INFO to KERN_DEBUG."

> Signed-off-by: Mike Travis <travis@sgi.com>
> ---
>  drivers/acpi/fan.c            |    2 +-
>  drivers/acpi/processor_core.c |    2 +-
>  drivers/acpi/tables.c         |   28 +++++++++++++++++++---------
>  3 files changed, 21 insertions(+), 11 deletions(-)
> 
> --- linux.orig/drivers/acpi/fan.c
> +++ linux/drivers/acpi/fan.c
> @@ -267,7 +267,7 @@
>  		goto end;
>  	}
>  
> -	dev_info(&device->dev, "registered as cooling_device%d\n", cdev->id);
> +	dev_dbg(&device->dev, "registered as cooling_device%d\n", cdev->id);
>  
>  	device->driver_data = cdev;
>  	result = sysfs_create_link(&device->dev.kobj,
> --- linux.orig/drivers/acpi/processor_core.c
> +++ linux/drivers/acpi/processor_core.c
> @@ -845,7 +845,7 @@
>  		goto err_power_exit;
>  	}
>  
> -	dev_info(&device->dev, "registered as cooling_device%d\n",
> +	dev_dbg(&device->dev, "registered as cooling_device%d\n",
>  		 pr->cdev->id);
>  
>  	result = sysfs_create_link(&device->dev.kobj,
> --- linux.orig/drivers/acpi/tables.c
> +++ linux/drivers/acpi/tables.c
> @@ -66,11 +66,15 @@
>  		{
>  			struct acpi_madt_local_x2apic *p =
>  			    (struct acpi_madt_local_x2apic *)header;
> -			printk(KERN_INFO PREFIX
> -			       "X2APIC (apic_id[0x%02x] uid[0x%02x] %s)\n",
> -			       p->local_apic_id, p->uid,
> -			       (p->lapic_flags & ACPI_MADT_ENABLED) ?
> -			       "enabled" : "disabled");
> +			/*
> +			 * Per cpu tracing clogs console output when NR_CPUS
> +			 * is large.  Send only to kernel log buffer.
> +			 */
> +			printk(KERN_DEBUG PREFIX
> +				"X2APIC (apic_id[0x%02x] uid[0x%02x] %s)\n",
> +				p->local_apic_id, p->uid,
> +				(p->lapic_flags & ACPI_MADT_ENABLED) ?
> +					"enabled" : "disabled");
>  		}
>  		break;
>  

You can still use dev_dbg(PREFIX "...") here.

> @@ -171,10 +175,16 @@
>  		{
>  			struct acpi_madt_local_sapic *p =
>  			    (struct acpi_madt_local_sapic *)header;
> -			printk(KERN_INFO PREFIX
> -			       "LSAPIC (acpi_id[0x%02x] lsapic_id[0x%02x] lsapic_eid[0x%02x] %s)\n",
> -			       p->processor_id, p->id, p->eid,
> -			       (p->lapic_flags & ACPI_MADT_ENABLED) ? "enabled" : "disabled");
> +			/*
> +			 * Per cpu tracing clogs console output when NR_CPUS
> +			 * is large.  Send only to kernel log buffer.
> +			 */
> +			printk(KERN_DEBUG PREFIX
> +				"LSAPIC (acpi_id[0x%02x] lsapic_id[0x%02x] "
> +				"lsapic_eid[0x%02x] %s)\n",
> +				p->processor_id, p->id, p->eid,
> +				(p->lapic_flags & ACPI_MADT_ENABLED) ?
> +					"enabled" : "disabled");
>  		}
>  		break;
>  

Likewise, but recent emails from Linus indicate that we don't want to 
break printk strings into multiple lines even if it goes over 80 
characters unless broken at '\n'.  Users who grep for 
"lsapic_id.*lsapic_eid" with this patch wouldn't find the string.

Re: [PATCH 2/7] ACPI: Limit the number of per cpu ACPI bootup messages

[Mike Travis]

David Rientjes wrote:
> On Thu, 12 Nov 2009, Mike Travis wrote:
> 
>> Limit the number of per cpu ACPI messages when system is booting to
>> prevent clogging up the console output with repetitious messages.
>>
> 
> ... "by changing the log level from KERN_INFO to KERN_DEBUG."
> 
>> Signed-off-by: Mike Travis <travis@sgi.com>
>> ---
>>  drivers/acpi/fan.c            |    2 +-
>>  drivers/acpi/processor_core.c |    2 +-
>>  drivers/acpi/tables.c         |   28 +++++++++++++++++++---------
>>  3 files changed, 21 insertions(+), 11 deletions(-)
>>
>> --- linux.orig/drivers/acpi/fan.c
>> +++ linux/drivers/acpi/fan.c
>> @@ -267,7 +267,7 @@
>>  		goto end;
>>  	}
>>  
>> -	dev_info(&device->dev, "registered as cooling_device%d\n", cdev->id);
>> +	dev_dbg(&device->dev, "registered as cooling_device%d\n", cdev->id);
>>  
>>  	device->driver_data = cdev;
>>  	result = sysfs_create_link(&device->dev.kobj,
>> --- linux.orig/drivers/acpi/processor_core.c
>> +++ linux/drivers/acpi/processor_core.c
>> @@ -845,7 +845,7 @@
>>  		goto err_power_exit;
>>  	}
>>  
>> -	dev_info(&device->dev, "registered as cooling_device%d\n",
>> +	dev_dbg(&device->dev, "registered as cooling_device%d\n",
>>  		 pr->cdev->id);
>>  
>>  	result = sysfs_create_link(&device->dev.kobj,
>> --- linux.orig/drivers/acpi/tables.c
>> +++ linux/drivers/acpi/tables.c
>> @@ -66,11 +66,15 @@
>>  		{
>>  			struct acpi_madt_local_x2apic *p =
>>  			    (struct acpi_madt_local_x2apic *)header;
>> -			printk(KERN_INFO PREFIX
>> -			       "X2APIC (apic_id[0x%02x] uid[0x%02x] %s)\n",
>> -			       p->local_apic_id, p->uid,
>> -			       (p->lapic_flags & ACPI_MADT_ENABLED) ?
>> -			       "enabled" : "disabled");
>> +			/*
>> +			 * Per cpu tracing clogs console output when NR_CPUS
>> +			 * is large.  Send only to kernel log buffer.
>> +			 */
>> +			printk(KERN_DEBUG PREFIX
>> +				"X2APIC (apic_id[0x%02x] uid[0x%02x] %s)\n",
>> +				p->local_apic_id, p->uid,
>> +				(p->lapic_flags & ACPI_MADT_ENABLED) ?
>> +					"enabled" : "disabled");
>>  		}
>>  		break;
>>  
> 
> You can still use dev_dbg(PREFIX "...") here.

I thought dev_dbg needed the 'dev' structure and I wasn't sure how to get that...?

> 
>> @@ -171,10 +175,16 @@
>>  		{
>>  			struct acpi_madt_local_sapic *p =
>>  			    (struct acpi_madt_local_sapic *)header;
>> -			printk(KERN_INFO PREFIX
>> -			       "LSAPIC (acpi_id[0x%02x] lsapic_id[0x%02x] lsapic_eid[0x%02x] %s)\n",
>> -			       p->processor_id, p->id, p->eid,
>> -			       (p->lapic_flags & ACPI_MADT_ENABLED) ? "enabled" : "disabled");
>> +			/*
>> +			 * Per cpu tracing clogs console output when NR_CPUS
>> +			 * is large.  Send only to kernel log buffer.
>> +			 */
>> +			printk(KERN_DEBUG PREFIX
>> +				"LSAPIC (acpi_id[0x%02x] lsapic_id[0x%02x] "
>> +				"lsapic_eid[0x%02x] %s)\n",
>> +				p->processor_id, p->id, p->eid,
>> +				(p->lapic_flags & ACPI_MADT_ENABLED) ?
>> +					"enabled" : "disabled");
>>  		}
>>  		break;
>>  
> 
> Likewise, but recent emails from Linus indicate that we don't want to 
> break printk strings into multiple lines even if it goes over 80 
> characters unless broken at '\n'.  Users who grep for 
> "lsapic_id.*lsapic_eid" with this patch wouldn't find the string.

Ahh, ok, I hadn't heard that yet.  (Grep just needs to be made smarter... ;-)

Thanks,
Mike

Re: [PATCH 2/7] ACPI: Limit the number of per cpu ACPI bootup messages

[David Rientjes]

On Thu, 12 Nov 2009, Mike Travis wrote:

> > > --- linux.orig/drivers/acpi/tables.c
> > > +++ linux/drivers/acpi/tables.c
> > > @@ -66,11 +66,15 @@
> > >  		{
> > >  			struct acpi_madt_local_x2apic *p =
> > >  			    (struct acpi_madt_local_x2apic *)header;
> > > -			printk(KERN_INFO PREFIX
> > > -			       "X2APIC (apic_id[0x%02x] uid[0x%02x] %s)\n",
> > > -			       p->local_apic_id, p->uid,
> > > -			       (p->lapic_flags & ACPI_MADT_ENABLED) ?
> > > -			       "enabled" : "disabled");
> > > +			/*
> > > +			 * Per cpu tracing clogs console output when NR_CPUS
> > > +			 * is large.  Send only to kernel log buffer.
> > > +			 */
> > > +			printk(KERN_DEBUG PREFIX
> > > +				"X2APIC (apic_id[0x%02x] uid[0x%02x] %s)\n",
> > > +				p->local_apic_id, p->uid,
> > > +				(p->lapic_flags & ACPI_MADT_ENABLED) ?
> > > +					"enabled" : "disabled");
> > >  		}
> > >  		break;
> > >  
> > 
> > You can still use dev_dbg(PREFIX "...") here.
> 
> I thought dev_dbg needed the 'dev' structure and I wasn't sure how to get
> that...?
> 

Ah, ok, it needs to be pr_debug(PREFIX "...") then.

Any reason why the other printk's in acpi_table_print_madt_entry() weren't 
converted to use KERN_DEBUG?  It might make more sense to convert all 
those to use a new acpi=verbose flag.

I'm not sure if Ingo is the right person to go through for acpi patches, I 
think this should probably be submitted to Len Brown <lenb@kernel.org> and 
linux-acpi@vger.kernel.org instead.

Re: [PATCH 2/7] ACPI: Limit the number of per cpu ACPI bootup messages

[Mike Travis]

David Rientjes wrote:
> On Thu, 12 Nov 2009, Mike Travis wrote:
> 
>>>> --- linux.orig/drivers/acpi/tables.c
>>>> +++ linux/drivers/acpi/tables.c
>>>> @@ -66,11 +66,15 @@
>>>>  		{
>>>>  			struct acpi_madt_local_x2apic *p =
>>>>  			    (struct acpi_madt_local_x2apic *)header;
>>>> -			printk(KERN_INFO PREFIX
>>>> -			       "X2APIC (apic_id[0x%02x] uid[0x%02x] %s)\n",
>>>> -			       p->local_apic_id, p->uid,
>>>> -			       (p->lapic_flags & ACPI_MADT_ENABLED) ?
>>>> -			       "enabled" : "disabled");
>>>> +			/*
>>>> +			 * Per cpu tracing clogs console output when NR_CPUS
>>>> +			 * is large.  Send only to kernel log buffer.
>>>> +			 */
>>>> +			printk(KERN_DEBUG PREFIX
>>>> +				"X2APIC (apic_id[0x%02x] uid[0x%02x] %s)\n",
>>>> +				p->local_apic_id, p->uid,
>>>> +				(p->lapic_flags & ACPI_MADT_ENABLED) ?
>>>> +					"enabled" : "disabled");
>>>>  		}
>>>>  		break;
>>>>  
>>> You can still use dev_dbg(PREFIX "...") here.
>> I thought dev_dbg needed the 'dev' structure and I wasn't sure how to get
>> that...?
>>
> 
> Ah, ok, it needs to be pr_debug(PREFIX "...") then.

The primary reason I'm using KERN_DEBUG instead of pr_debug is that the
messages will end up in the log in the former case, so dmesg can print
them out, whether it's a DEBUG kernel or not.  This helps diagnose problems
without requiring a reboot of a DEBUG kernel to reproduce a problem, which
often is not acceptable to many customers (security and system availability
being the primary concerns.)

> Any reason why the other printk's in acpi_table_print_madt_entry() weren't 
> converted to use KERN_DEBUG?  It might make more sense to convert all 
> those to use a new acpi=verbose flag.

I thought of that, but the ACPI debug infrastructure is complex to understand,
and since I can't really test most cases, I wanted to tread lightly.
> 
> I'm not sure if Ingo is the right person to go through for acpi patches, I 
> think this should probably be submitted to Len Brown <lenb@kernel.org> and 
> linux-acpi@vger.kernel.org instead.

I can do that.

Thanks,
Mike

[PATCH 3/7] INIT: Limit the number of per cpu INIT bootup messages

[Mike Travis]

[-- Attachment #1: limit_init_boot_messages --]
[-- Type: text/plain, Size: 2133 bytes --]

Limit the number of per cpu INIT messages when system is booting to
prevent clogging up the console output with repetitious messages.

Signed-off-by: Mike Travis <travis@sgi.com>
---
 init/calibrate.c |   22 +++++++++++++---------
 kernel/cpu.c     |    5 ++---
 2 files changed, 15 insertions(+), 12 deletions(-)

--- linux.orig/init/calibrate.c
+++ linux/init/calibrate.c
@@ -123,23 +123,26 @@
 {
 	unsigned long ticks, loopbit;
 	int lps_precision = LPS_PREC;
+	bool boot_cpu = (smp_processor_id() == 0);
 
 	if (preset_lpj) {
 		loops_per_jiffy = preset_lpj;
-		printk(KERN_INFO
-			"Calibrating delay loop (skipped) preset value.. ");
-	} else if ((smp_processor_id() == 0) && lpj_fine) {
+		if (boot_cpu)
+			pr_info("Calibrating delay loop (skipped) "
+				"preset value.. ");
+	} else if ((boot_cpu) && lpj_fine) {
 		loops_per_jiffy = lpj_fine;
-		printk(KERN_INFO
-			"Calibrating delay loop (skipped), "
+		pr_info("Calibrating delay loop (skipped), "
 			"value calculated using timer frequency.. ");
 	} else if ((loops_per_jiffy = calibrate_delay_direct()) != 0) {
-		printk(KERN_INFO
-			"Calibrating delay using timer specific routine.. ");
+		if (boot_cpu)
+			pr_info("Calibrating delay using timer "
+				"specific routine.. ");
 	} else {
 		loops_per_jiffy = (1<<12);
 
-		printk(KERN_INFO "Calibrating delay loop... ");
+		if (boot_cpu)
+			pr_info("Calibrating delay loop... ");
 		while ((loops_per_jiffy <<= 1) != 0) {
 			/* wait for "start of" clock tick */
 			ticks = jiffies;
@@ -170,7 +173,8 @@
 				loops_per_jiffy &= ~loopbit;
 		}
 	}
-	printk(KERN_CONT "%lu.%02lu BogoMIPS (lpj=%lu)\n",
+	if (boot_cpu)
+		pr_cont("%lu.%02lu BogoMIPS (lpj=%lu)\n",
 			loops_per_jiffy/(500000/HZ),
 			(loops_per_jiffy/(5000/HZ)) % 100, loops_per_jiffy);
 }
--- linux.orig/kernel/cpu.c
+++ linux/kernel/cpu.c
@@ -392,10 +392,9 @@
 		if (cpu == first_cpu)
 			continue;
 		error = _cpu_down(cpu, 1);
-		if (!error) {
+		if (!error)
 			cpumask_set_cpu(cpu, frozen_cpus);
-			printk("CPU%d is down\n", cpu);
-		} else {
+		else {
 			printk(KERN_ERR "Error taking CPU%d down: %d\n",
 				cpu, error);
 			break;

-- 

Re: [PATCH 3/7] INIT: Limit the number of per cpu INIT bootup messages

[David Rientjes]

On Thu, 12 Nov 2009, Mike Travis wrote:

> Limit the number of per cpu INIT messages when system is booting to
> prevent clogging up the console output with repetitious messages.
> 

Needs a better changelog.  What did you do to effect that change?  It 
looks like you're only emitting certain messages from the boot cpu.

> Signed-off-by: Mike Travis <travis@sgi.com>
> ---
>  init/calibrate.c |   22 +++++++++++++---------
>  kernel/cpu.c     |    5 ++---
>  2 files changed, 15 insertions(+), 12 deletions(-)
> 
> --- linux.orig/init/calibrate.c
> +++ linux/init/calibrate.c
> @@ -123,23 +123,26 @@
>  {
>  	unsigned long ticks, loopbit;
>  	int lps_precision = LPS_PREC;
> +	bool boot_cpu = (smp_processor_id() == 0);
>  
>  	if (preset_lpj) {
>  		loops_per_jiffy = preset_lpj;
> -		printk(KERN_INFO
> -			"Calibrating delay loop (skipped) preset value.. ");
> -	} else if ((smp_processor_id() == 0) && lpj_fine) {
> +		if (boot_cpu)
> +			pr_info("Calibrating delay loop (skipped) "
> +				"preset value.. ");

Same comment as before about breaking printk strings into multiple lines 
when not broken at '\n'.  All the other patches your series look good 
after this, however.

> +	} else if ((boot_cpu) && lpj_fine) {

Parentheses around boot_cpu?

>  		loops_per_jiffy = lpj_fine;
> -		printk(KERN_INFO
> -			"Calibrating delay loop (skipped), "
> +		pr_info("Calibrating delay loop (skipped), "
>  			"value calculated using timer frequency.. ");
>  	} else if ((loops_per_jiffy = calibrate_delay_direct()) != 0) {
> -		printk(KERN_INFO
> -			"Calibrating delay using timer specific routine.. ");
> +		if (boot_cpu)
> +			pr_info("Calibrating delay using timer "
> +				"specific routine.. ");
>  	} else {
>  		loops_per_jiffy = (1<<12);
>  
> -		printk(KERN_INFO "Calibrating delay loop... ");
> +		if (boot_cpu)
> +			pr_info("Calibrating delay loop... ");
>  		while ((loops_per_jiffy <<= 1) != 0) {
>  			/* wait for "start of" clock tick */
>  			ticks = jiffies;
> @@ -170,7 +173,8 @@
>  				loops_per_jiffy &= ~loopbit;
>  		}
>  	}
> -	printk(KERN_CONT "%lu.%02lu BogoMIPS (lpj=%lu)\n",
> +	if (boot_cpu)
> +		pr_cont("%lu.%02lu BogoMIPS (lpj=%lu)\n",
>  			loops_per_jiffy/(500000/HZ),
>  			(loops_per_jiffy/(5000/HZ)) % 100, loops_per_jiffy);
>  }
> --- linux.orig/kernel/cpu.c
> +++ linux/kernel/cpu.c
> @@ -392,10 +392,9 @@
>  		if (cpu == first_cpu)
>  			continue;
>  		error = _cpu_down(cpu, 1);
> -		if (!error) {
> +		if (!error)
>  			cpumask_set_cpu(cpu, frozen_cpus);
> -			printk("CPU%d is down\n", cpu);
> -		} else {
> +		else {
>  			printk(KERN_ERR "Error taking CPU%d down: %d\n",
>  				cpu, error);
>  			break;

Re: [PATCH 3/7] INIT: Limit the number of per cpu INIT bootup messages

[Mike Travis]

Hmm, yes I agree, too much cut and paste.  Will update. -thanks!

David Rientjes wrote:
> On Thu, 12 Nov 2009, Mike Travis wrote:
> 
>> Limit the number of per cpu INIT messages when system is booting to
>> prevent clogging up the console output with repetitious messages.
>>
> 
> Needs a better changelog.  What did you do to effect that change?  It 
> looks like you're only emitting certain messages from the boot cpu.
> 
>> Signed-off-by: Mike Travis <travis@sgi.com>
>> ---
>>  init/calibrate.c |   22 +++++++++++++---------
>>  kernel/cpu.c     |    5 ++---
>>  2 files changed, 15 insertions(+), 12 deletions(-)
>>
>> --- linux.orig/init/calibrate.c
>> +++ linux/init/calibrate.c
>> @@ -123,23 +123,26 @@
>>  {
>>  	unsigned long ticks, loopbit;
>>  	int lps_precision = LPS_PREC;
>> +	bool boot_cpu = (smp_processor_id() == 0);
>>  
>>  	if (preset_lpj) {
>>  		loops_per_jiffy = preset_lpj;
>> -		printk(KERN_INFO
>> -			"Calibrating delay loop (skipped) preset value.. ");
>> -	} else if ((smp_processor_id() == 0) && lpj_fine) {
>> +		if (boot_cpu)
>> +			pr_info("Calibrating delay loop (skipped) "
>> +				"preset value.. ");
> 
> Same comment as before about breaking printk strings into multiple lines 
> when not broken at '\n'.  All the other patches your series look good 
> after this, however.
> 
>> +	} else if ((boot_cpu) && lpj_fine) {
> 
> Parentheses around boot_cpu?
> 
>>  		loops_per_jiffy = lpj_fine;
>> -		printk(KERN_INFO
>> -			"Calibrating delay loop (skipped), "
>> +		pr_info("Calibrating delay loop (skipped), "
>>  			"value calculated using timer frequency.. ");
>>  	} else if ((loops_per_jiffy = calibrate_delay_direct()) != 0) {
>> -		printk(KERN_INFO
>> -			"Calibrating delay using timer specific routine.. ");
>> +		if (boot_cpu)
>> +			pr_info("Calibrating delay using timer "
>> +				"specific routine.. ");
>>  	} else {
>>  		loops_per_jiffy = (1<<12);
>>  
>> -		printk(KERN_INFO "Calibrating delay loop... ");
>> +		if (boot_cpu)
>> +			pr_info("Calibrating delay loop... ");
>>  		while ((loops_per_jiffy <<= 1) != 0) {
>>  			/* wait for "start of" clock tick */
>>  			ticks = jiffies;
>> @@ -170,7 +173,8 @@
>>  				loops_per_jiffy &= ~loopbit;
>>  		}
>>  	}
>> -	printk(KERN_CONT "%lu.%02lu BogoMIPS (lpj=%lu)\n",
>> +	if (boot_cpu)
>> +		pr_cont("%lu.%02lu BogoMIPS (lpj=%lu)\n",
>>  			loops_per_jiffy/(500000/HZ),
>>  			(loops_per_jiffy/(5000/HZ)) % 100, loops_per_jiffy);
>>  }
>> --- linux.orig/kernel/cpu.c
>> +++ linux/kernel/cpu.c
>> @@ -392,10 +392,9 @@
>>  		if (cpu == first_cpu)
>>  			continue;
>>  		error = _cpu_down(cpu, 1);
>> -		if (!error) {
>> +		if (!error)
>>  			cpumask_set_cpu(cpu, frozen_cpus);
>> -			printk("CPU%d is down\n", cpu);
>> -		} else {
>> +		else {
>>  			printk(KERN_ERR "Error taking CPU%d down: %d\n",
>>  				cpu, error);
>>  			break;

[PATCH 4/7] firmware: Limit the number of per cpu firmware messages during bootup

[Mike Travis]

[-- Attachment #1: limit_firmware_messages --]
[-- Type: text/plain, Size: 659 bytes --]

Limit the number of per cpu firmware: messages when system is booting to
prevent clogging up the console output with repetitious messages.

[  170.643130] firmware: requesting intel-ucode/06-2e-0

Signed-off-by: Mike Travis <travis@sgi.com>
---
 drivers/base/firmware_class.c |    2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

--- linux.orig/drivers/base/firmware_class.c
+++ linux/drivers/base/firmware_class.c
@@ -495,7 +495,7 @@
 	}
 
 	if (uevent)
-		dev_info(device, "firmware: requesting %s\n", name);
+		dev_dbg(device, "firmware: requesting %s\n", name);
 
 	retval = fw_setup_device(firmware, &f_dev, name, device, uevent);
 	if (retval)

-- 

[PATCH 5/7] x86: Limit the number of per cpu MCE bootup messages

[Mike Travis]

[-- Attachment #1: limit_mce_messages.v1 --]
[-- Type: text/plain, Size: 1163 bytes --]

Limit the number of per cpu MCE messages when system is booting to
prevent clogging up the console output with repetitious messages.

Signed-off-by: Mike Travis <travis@sgi.com>
---
 arch/x86/kernel/cpu/mcheck/mce.c       |    4 ++--
 arch/x86/kernel/cpu/mcheck/mce_intel.c |    2 +-
 2 files changed, 3 insertions(+), 3 deletions(-)

--- linux.orig/arch/x86/kernel/cpu/mcheck/mce.c
+++ linux/arch/x86/kernel/cpu/mcheck/mce.c
@@ -1215,10 +1215,10 @@
 
 	b = cap & MCG_BANKCNT_MASK;
 	if (!banks)
-		printk(KERN_INFO "mce: CPU supports %d MCE banks\n", b);
+		pr_debug("mce: CPU supports %d MCE banks\n", b);
 
 	if (b > MAX_NR_BANKS) {
-		printk(KERN_WARNING
+		pr_warning(
 		       "MCE: Using only %u machine check banks out of %u\n",
 			MAX_NR_BANKS, b);
 		b = MAX_NR_BANKS;
--- linux.orig/arch/x86/kernel/cpu/mcheck/mce_intel.c
+++ linux/arch/x86/kernel/cpu/mcheck/mce_intel.c
@@ -67,7 +67,7 @@
 static void print_update(char *type, int *hdr, int num)
 {
 	if (*hdr == 0)
-		printk(KERN_INFO "CPU %d MCA banks", smp_processor_id());
+		printk(KERN_DEBUG "CPU %d MCA banks", smp_processor_id());
 	*hdr = 1;
 	printk(KERN_CONT " %s:%d", type, num);
 }

-- 

[PATCH 6/7] sched: Limit the number of scheduler debug messages

[Mike Travis]

[-- Attachment #1: limit_sched_debug_messages --]
[-- Type: text/plain, Size: 710 bytes --]

Limit number of sched debug messages for MAXSMP systems.

Signed-off-by: Mike Travis <travis@sgi.com>
---
 lib/Kconfig.debug |    5 +++--
 1 file changed, 3 insertions(+), 2 deletions(-)

--- linux.orig/lib/Kconfig.debug
+++ linux/lib/Kconfig.debug
@@ -235,11 +235,12 @@
 config SCHED_DEBUG
 	bool "Collect scheduler debugging info"
 	depends on DEBUG_KERNEL && PROC_FS
-	default y
+	default !MAXSMP
 	help
 	  If you say Y here, the /proc/sched_debug file will be provided
 	  that can help debug the scheduler. The runtime overhead of this
-	  option is minimal.
+	  option is minimal unless there are a large number of CPUs in
+	  the system.
 
 config SCHEDSTATS
 	bool "Collect scheduler statistics"

-- 

[PATCH 7/7] x86: Limit number of per cpu TSC sync messages

[Mike Travis]

[-- Attachment #1: limit_tsc_sync_messages --]
[-- Type: text/plain, Size: 991 bytes --]

Limit the number of per cpu TSC sync messages when system is booting to
prevent clogging up the console output with repetitious messages.

Signed-off-by: Mike Travis <travis@sgi.com>
---
 arch/x86/kernel/tsc_sync.c |    8 +++-----
 1 file changed, 3 insertions(+), 5 deletions(-)

--- linux.orig/arch/x86/kernel/tsc_sync.c
+++ linux/arch/x86/kernel/tsc_sync.c
@@ -118,9 +118,6 @@
 		return;
 	}
 
-	pr_info("checking TSC synchronization [CPU#%d -> CPU#%d]:",
-		smp_processor_id(), cpu);
-
 	/*
 	 * Reset it - in case this is a second bootup:
 	 */
@@ -142,12 +139,13 @@
 		cpu_relax();
 
 	if (nr_warps) {
-		printk("\n");
+		pr_warning("TSC synchronization [CPU#%d -> CPU#%d]:\n",
+			smp_processor_id(), cpu);
 		pr_warning("Measured %Ld cycles TSC warp between CPUs, "
 			   "turning off TSC clock.\n", max_warp);
 		mark_tsc_unstable("check_tsc_sync_source failed");
 	} else {
-		printk(" passed.\n");
+		pr_debug("TSC synchronization [CPU#%d -> CPU#%d]: passed\n");
 	}
 
 	/*

-- 

[patch] x86: reduce srat verbosity in the kernel log

[David Rientjes]

It's possible to reduce the number of SRAT messages emitted to the kernel
log by printing each valid pxm once and then creating bitmaps to represent
the apic ids that map to the same node.

This reduces lines such as

	SRAT: PXM 0 -> APIC 0 -> Node 0
	SRAT: PXM 0 -> APIC 1 -> Node 0
	SRAT: PXM 1 -> APIC 2 -> Node 1
	SRAT: PXM 1 -> APIC 3 -> Node 1

to

	SRAT: PXM 0 -> APIC {0-1} -> Node 0
	SRAT: PXM 1 -> APIC {2-3} -> Node 1

The buffer used to store the apic id list is 128 characters in length.
If that is too small to represent all the apic id ranges that are bound
to a single pxm, a trailing "..." is added.  APICID_LIST_LEN should be
manually increased for such configurations.

Acked-by: Mike Travis <travis@sgi.com>
Signed-off-by: David Rientjes <rientjes@google.com>
---
 arch/x86/mm/srat_64.c |   41 +++++++++++++++++++++++++++++++++++++----
 drivers/acpi/numa.c   |    5 +++++
 include/linux/acpi.h  |    3 ++-
 3 files changed, 44 insertions(+), 5 deletions(-)

diff --git a/arch/x86/mm/srat_64.c b/arch/x86/mm/srat_64.c
--- a/arch/x86/mm/srat_64.c
+++ b/arch/x86/mm/srat_64.c
@@ -36,6 +36,9 @@ static int num_node_memblks __initdata;
 static struct bootnode node_memblk_range[NR_NODE_MEMBLKS] __initdata;
 static int memblk_nodeid[NR_NODE_MEMBLKS] __initdata;
 
+static DECLARE_BITMAP(apicid_map, MAX_LOCAL_APIC) __initdata;
+#define APICID_LIST_LEN	(128)
+
 static __init int setup_node(int pxm)
 {
 	return acpi_map_pxm_to_node(pxm);
@@ -136,8 +139,6 @@ acpi_numa_x2apic_affinity_init(struct acpi_srat_x2apic_cpu_affinity *pa)
 	apicid_to_node[apic_id] = node;
 	node_set(node, cpu_nodes_parsed);
 	acpi_numa = 1;
-	printk(KERN_INFO "SRAT: PXM %u -> APIC %u -> Node %u\n",
-	       pxm, apic_id, node);
 }
 
 /* Callback for Proximity Domain -> LAPIC mapping */
@@ -170,8 +171,40 @@ acpi_numa_processor_affinity_init(struct acpi_srat_cpu_affinity *pa)
 	apicid_to_node[apic_id] = node;
 	node_set(node, cpu_nodes_parsed);
 	acpi_numa = 1;
-	printk(KERN_INFO "SRAT: PXM %u -> APIC %u -> Node %u\n",
-	       pxm, apic_id, node);
+}
+
+void __init acpi_numa_print_srat_mapping(void)
+{
+	char apicid_list[APICID_LIST_LEN];
+	int i, j;
+
+	for (i = 0; i < MAX_PXM_DOMAINS; i++) {
+		int len;
+		int nid;
+
+		nid = pxm_to_node(i);
+		if (nid == NUMA_NO_NODE)
+			continue;
+
+		bitmap_zero(apicid_map, MAX_LOCAL_APIC);
+		for (j = 0; j < MAX_LOCAL_APIC; j++)
+			if (apicid_to_node[j] == nid)
+				set_bit(j, apicid_map);
+
+		if (bitmap_empty(apicid_map, MAX_LOCAL_APIC))
+			continue;
+
+		/*
+		 * If the bitmap cannot be listed in a buffer of length
+		 * APICID_LIST_LEN, then it is suffixed with "...".
+		 */
+		len = bitmap_scnlistprintf(apicid_list, APICID_LIST_LEN,
+					   apicid_map, MAX_LOCAL_APIC);
+		pr_info("SRAT: PXM %u -> APIC {%s%s} -> Node %u\n",
+			i, apicid_list,
+			(len == APICID_LIST_LEN - 1) ? "..." : "",
+			nid);
+	}
 }
 
 #ifdef CONFIG_MEMORY_HOTPLUG_SPARSE
diff --git a/drivers/acpi/numa.c b/drivers/acpi/numa.c
--- a/drivers/acpi/numa.c
+++ b/drivers/acpi/numa.c
@@ -281,6 +281,10 @@ acpi_table_parse_srat(enum acpi_srat_type id,
 					    handler, max_entries);
 }
 
+void __init __attribute__((weak)) acpi_numa_print_srat_mapping(void)
+{
+}
+
 int __init acpi_numa_init(void)
 {
 	/* SRAT: Static Resource Affinity Table */
@@ -292,6 +296,7 @@ int __init acpi_numa_init(void)
 		acpi_table_parse_srat(ACPI_SRAT_TYPE_MEMORY_AFFINITY,
 				      acpi_parse_memory_affinity,
 				      NR_NODE_MEMBLKS);
+		acpi_numa_print_srat_mapping();
 	}
 
 	/* SLIT: System Locality Information Table */
diff --git a/include/linux/acpi.h b/include/linux/acpi.h
--- a/include/linux/acpi.h
+++ b/include/linux/acpi.h
@@ -92,12 +92,13 @@ int acpi_table_parse_madt (enum acpi_madt_type id, acpi_table_entry_handler hand
 int acpi_parse_mcfg (struct acpi_table_header *header);
 void acpi_table_print_madt_entry (struct acpi_subtable_header *madt);
 
-/* the following four functions are architecture-dependent */
+/* the following six functions are architecture-dependent */
 void acpi_numa_slit_init (struct acpi_table_slit *slit);
 void acpi_numa_processor_affinity_init (struct acpi_srat_cpu_affinity *pa);
 void acpi_numa_x2apic_affinity_init(struct acpi_srat_x2apic_cpu_affinity *pa);
 void acpi_numa_memory_affinity_init (struct acpi_srat_mem_affinity *ma);
 void acpi_numa_arch_fixup(void);
+void acpi_numa_print_srat_mapping(void);
 
 #ifdef CONFIG_ACPI_HOTPLUG_CPU
 /* Arch dependent functions for cpu hotplug support */

Re: [patch] x86: reduce srat verbosity in the kernel log

[Ingo Molnar]

* David Rientjes <rientjes@google.com> wrote:

> It's possible to reduce the number of SRAT messages emitted to the kernel
> log by printing each valid pxm once and then creating bitmaps to represent
> the apic ids that map to the same node.
> 
> This reduces lines such as
> 
> 	SRAT: PXM 0 -> APIC 0 -> Node 0
> 	SRAT: PXM 0 -> APIC 1 -> Node 0
> 	SRAT: PXM 1 -> APIC 2 -> Node 1
> 	SRAT: PXM 1 -> APIC 3 -> Node 1
> 
> to
> 
> 	SRAT: PXM 0 -> APIC {0-1} -> Node 0
> 	SRAT: PXM 1 -> APIC {2-3} -> Node 1
> 
> The buffer used to store the apic id list is 128 characters in length.
> If that is too small to represent all the apic id ranges that are bound
> to a single pxm, a trailing "..." is added.  APICID_LIST_LEN should be
> manually increased for such configurations.
> 
> Acked-by: Mike Travis <travis@sgi.com>
> Signed-off-by: David Rientjes <rientjes@google.com>
> ---
>  arch/x86/mm/srat_64.c |   41 +++++++++++++++++++++++++++++++++++++----
>  drivers/acpi/numa.c   |    5 +++++
>  include/linux/acpi.h  |    3 ++-
>  3 files changed, 44 insertions(+), 5 deletions(-)
> 
> diff --git a/arch/x86/mm/srat_64.c b/arch/x86/mm/srat_64.c
> --- a/arch/x86/mm/srat_64.c
> +++ b/arch/x86/mm/srat_64.c
> @@ -36,6 +36,9 @@ static int num_node_memblks __initdata;
>  static struct bootnode node_memblk_range[NR_NODE_MEMBLKS] __initdata;
>  static int memblk_nodeid[NR_NODE_MEMBLKS] __initdata;
>  
> +static DECLARE_BITMAP(apicid_map, MAX_LOCAL_APIC) __initdata;
> +#define APICID_LIST_LEN	(128)
> +
>  static __init int setup_node(int pxm)
>  {
>  	return acpi_map_pxm_to_node(pxm);
> @@ -136,8 +139,6 @@ acpi_numa_x2apic_affinity_init(struct acpi_srat_x2apic_cpu_affinity *pa)
>  	apicid_to_node[apic_id] = node;
>  	node_set(node, cpu_nodes_parsed);
>  	acpi_numa = 1;
> -	printk(KERN_INFO "SRAT: PXM %u -> APIC %u -> Node %u\n",
> -	       pxm, apic_id, node);
>  }
>  
>  /* Callback for Proximity Domain -> LAPIC mapping */
> @@ -170,8 +171,40 @@ acpi_numa_processor_affinity_init(struct acpi_srat_cpu_affinity *pa)
>  	apicid_to_node[apic_id] = node;
>  	node_set(node, cpu_nodes_parsed);
>  	acpi_numa = 1;
> -	printk(KERN_INFO "SRAT: PXM %u -> APIC %u -> Node %u\n",
> -	       pxm, apic_id, node);
> +}
> +
> +void __init acpi_numa_print_srat_mapping(void)
> +{
> +	char apicid_list[APICID_LIST_LEN];
> +	int i, j;
> +
> +	for (i = 0; i < MAX_PXM_DOMAINS; i++) {
> +		int len;
> +		int nid;
> +
> +		nid = pxm_to_node(i);
> +		if (nid == NUMA_NO_NODE)
> +			continue;
> +
> +		bitmap_zero(apicid_map, MAX_LOCAL_APIC);
> +		for (j = 0; j < MAX_LOCAL_APIC; j++)
> +			if (apicid_to_node[j] == nid)
> +				set_bit(j, apicid_map);
> +
> +		if (bitmap_empty(apicid_map, MAX_LOCAL_APIC))
> +			continue;
> +
> +		/*
> +		 * If the bitmap cannot be listed in a buffer of length
> +		 * APICID_LIST_LEN, then it is suffixed with "...".
> +		 */
> +		len = bitmap_scnlistprintf(apicid_list, APICID_LIST_LEN,
> +					   apicid_map, MAX_LOCAL_APIC);
> +		pr_info("SRAT: PXM %u -> APIC {%s%s} -> Node %u\n",
> +			i, apicid_list,
> +			(len == APICID_LIST_LEN - 1) ? "..." : "",
> +			nid);
> +	}
>  }

No. As i suggested many times before, just get rid of the printouts or 
make them boot-debug-flag dependent.

	Ingo

Re: [patch] x86: reduce srat verbosity in the kernel log

[David Rientjes]

On Fri, 13 Nov 2009, Ingo Molnar wrote:

> > It's possible to reduce the number of SRAT messages emitted to the kernel
> > log by printing each valid pxm once and then creating bitmaps to represent
> > the apic ids that map to the same node.
> > 
> > This reduces lines such as
> > 
> > 	SRAT: PXM 0 -> APIC 0 -> Node 0
> > 	SRAT: PXM 0 -> APIC 1 -> Node 0
> > 	SRAT: PXM 1 -> APIC 2 -> Node 1
> > 	SRAT: PXM 1 -> APIC 3 -> Node 1
> > 
> > to
> > 
> > 	SRAT: PXM 0 -> APIC {0-1} -> Node 0
> > 	SRAT: PXM 1 -> APIC {2-3} -> Node 1
> > 
> > The buffer used to store the apic id list is 128 characters in length.
> > If that is too small to represent all the apic id ranges that are bound
> > to a single pxm, a trailing "..." is added.  APICID_LIST_LEN should be
> > manually increased for such configurations.
> > 
> > Acked-by: Mike Travis <travis@sgi.com>
> > Signed-off-by: David Rientjes <rientjes@google.com>
> > ---
> >  arch/x86/mm/srat_64.c |   41 +++++++++++++++++++++++++++++++++++++----
> >  drivers/acpi/numa.c   |    5 +++++
> >  include/linux/acpi.h  |    3 ++-
> >  3 files changed, 44 insertions(+), 5 deletions(-)
> > 
> > diff --git a/arch/x86/mm/srat_64.c b/arch/x86/mm/srat_64.c
> > --- a/arch/x86/mm/srat_64.c
> > +++ b/arch/x86/mm/srat_64.c
> > @@ -36,6 +36,9 @@ static int num_node_memblks __initdata;
> >  static struct bootnode node_memblk_range[NR_NODE_MEMBLKS] __initdata;
> >  static int memblk_nodeid[NR_NODE_MEMBLKS] __initdata;
> >  
> > +static DECLARE_BITMAP(apicid_map, MAX_LOCAL_APIC) __initdata;
> > +#define APICID_LIST_LEN	(128)
> > +
> >  static __init int setup_node(int pxm)
> >  {
> >  	return acpi_map_pxm_to_node(pxm);
> > @@ -136,8 +139,6 @@ acpi_numa_x2apic_affinity_init(struct acpi_srat_x2apic_cpu_affinity *pa)
> >  	apicid_to_node[apic_id] = node;
> >  	node_set(node, cpu_nodes_parsed);
> >  	acpi_numa = 1;
> > -	printk(KERN_INFO "SRAT: PXM %u -> APIC %u -> Node %u\n",
> > -	       pxm, apic_id, node);
> >  }
> >  
> >  /* Callback for Proximity Domain -> LAPIC mapping */
> > @@ -170,8 +171,40 @@ acpi_numa_processor_affinity_init(struct acpi_srat_cpu_affinity *pa)
> >  	apicid_to_node[apic_id] = node;
> >  	node_set(node, cpu_nodes_parsed);
> >  	acpi_numa = 1;
> > -	printk(KERN_INFO "SRAT: PXM %u -> APIC %u -> Node %u\n",
> > -	       pxm, apic_id, node);
> > +}
> > +
> > +void __init acpi_numa_print_srat_mapping(void)
> > +{
> > +	char apicid_list[APICID_LIST_LEN];
> > +	int i, j;
> > +
> > +	for (i = 0; i < MAX_PXM_DOMAINS; i++) {
> > +		int len;
> > +		int nid;
> > +
> > +		nid = pxm_to_node(i);
> > +		if (nid == NUMA_NO_NODE)
> > +			continue;
> > +
> > +		bitmap_zero(apicid_map, MAX_LOCAL_APIC);
> > +		for (j = 0; j < MAX_LOCAL_APIC; j++)
> > +			if (apicid_to_node[j] == nid)
> > +				set_bit(j, apicid_map);
> > +
> > +		if (bitmap_empty(apicid_map, MAX_LOCAL_APIC))
> > +			continue;
> > +
> > +		/*
> > +		 * If the bitmap cannot be listed in a buffer of length
> > +		 * APICID_LIST_LEN, then it is suffixed with "...".
> > +		 */
> > +		len = bitmap_scnlistprintf(apicid_list, APICID_LIST_LEN,
> > +					   apicid_map, MAX_LOCAL_APIC);
> > +		pr_info("SRAT: PXM %u -> APIC {%s%s} -> Node %u\n",
> > +			i, apicid_list,
> > +			(len == APICID_LIST_LEN - 1) ? "..." : "",
> > +			nid);
> > +	}
> >  }
> 
> No. As i suggested many times before, just get rid of the printouts or 
> make them boot-debug-flag dependent.
> 

Hmm, so even if these were dependent on a kernel parameter, do you think 
this patch would still be needed exactly as it is written?  In other 
words, do you believe that Mark's system should really emit 1272 lines for 
this data instead of the 40 with this patch?

I'm all for making this dependent on a kernel parameter, but it's a 
seperate change than what this patch is addressing.  We need the apic id 
mappings because they aren't exposed to userspace in any other way, 
they need to exported somehow and this is a clear improvement to reduce 
verbosity in the kernel log.

So I really don't know what you're insisting here, you want this 
compression to be accompanied by another patch which makes the call to 
acpi_numa_print_srat_mapping() depend on a kernel parameter?  Or are you 
saying we shouldn't compress it at all and Mike should just deal with 1272 
lines instead of 40?  Or are you saying we should export this static 
information via sysfs?

Re: [patch] x86: reduce srat verbosity in the kernel log

[Ingo Molnar]

* David Rientjes <rientjes@google.com> wrote:

> On Fri, 13 Nov 2009, Ingo Molnar wrote:
> 
> > > It's possible to reduce the number of SRAT messages emitted to the kernel
> > > log by printing each valid pxm once and then creating bitmaps to represent
> > > the apic ids that map to the same node.
> > > 
> > > This reduces lines such as
> > > 
> > > 	SRAT: PXM 0 -> APIC 0 -> Node 0
> > > 	SRAT: PXM 0 -> APIC 1 -> Node 0
> > > 	SRAT: PXM 1 -> APIC 2 -> Node 1
> > > 	SRAT: PXM 1 -> APIC 3 -> Node 1
> > > 
> > > to
> > > 
> > > 	SRAT: PXM 0 -> APIC {0-1} -> Node 0
> > > 	SRAT: PXM 1 -> APIC {2-3} -> Node 1
> > > 
> > > The buffer used to store the apic id list is 128 characters in length.
> > > If that is too small to represent all the apic id ranges that are bound
> > > to a single pxm, a trailing "..." is added.  APICID_LIST_LEN should be
> > > manually increased for such configurations.
> > > 
> > > Acked-by: Mike Travis <travis@sgi.com>
> > > Signed-off-by: David Rientjes <rientjes@google.com>
> > > ---
> > >  arch/x86/mm/srat_64.c |   41 +++++++++++++++++++++++++++++++++++++----
> > >  drivers/acpi/numa.c   |    5 +++++
> > >  include/linux/acpi.h  |    3 ++-
> > >  3 files changed, 44 insertions(+), 5 deletions(-)
> > > 
> > > diff --git a/arch/x86/mm/srat_64.c b/arch/x86/mm/srat_64.c
> > > --- a/arch/x86/mm/srat_64.c
> > > +++ b/arch/x86/mm/srat_64.c
> > > @@ -36,6 +36,9 @@ static int num_node_memblks __initdata;
> > >  static struct bootnode node_memblk_range[NR_NODE_MEMBLKS] __initdata;
> > >  static int memblk_nodeid[NR_NODE_MEMBLKS] __initdata;
> > >  
> > > +static DECLARE_BITMAP(apicid_map, MAX_LOCAL_APIC) __initdata;
> > > +#define APICID_LIST_LEN	(128)
> > > +
> > >  static __init int setup_node(int pxm)
> > >  {
> > >  	return acpi_map_pxm_to_node(pxm);
> > > @@ -136,8 +139,6 @@ acpi_numa_x2apic_affinity_init(struct acpi_srat_x2apic_cpu_affinity *pa)
> > >  	apicid_to_node[apic_id] = node;
> > >  	node_set(node, cpu_nodes_parsed);
> > >  	acpi_numa = 1;
> > > -	printk(KERN_INFO "SRAT: PXM %u -> APIC %u -> Node %u\n",
> > > -	       pxm, apic_id, node);
> > >  }
> > >  
> > >  /* Callback for Proximity Domain -> LAPIC mapping */
> > > @@ -170,8 +171,40 @@ acpi_numa_processor_affinity_init(struct acpi_srat_cpu_affinity *pa)
> > >  	apicid_to_node[apic_id] = node;
> > >  	node_set(node, cpu_nodes_parsed);
> > >  	acpi_numa = 1;
> > > -	printk(KERN_INFO "SRAT: PXM %u -> APIC %u -> Node %u\n",
> > > -	       pxm, apic_id, node);
> > > +}
> > > +
> > > +void __init acpi_numa_print_srat_mapping(void)
> > > +{
> > > +	char apicid_list[APICID_LIST_LEN];
> > > +	int i, j;
> > > +
> > > +	for (i = 0; i < MAX_PXM_DOMAINS; i++) {
> > > +		int len;
> > > +		int nid;
> > > +
> > > +		nid = pxm_to_node(i);
> > > +		if (nid == NUMA_NO_NODE)
> > > +			continue;
> > > +
> > > +		bitmap_zero(apicid_map, MAX_LOCAL_APIC);
> > > +		for (j = 0; j < MAX_LOCAL_APIC; j++)
> > > +			if (apicid_to_node[j] == nid)
> > > +				set_bit(j, apicid_map);
> > > +
> > > +		if (bitmap_empty(apicid_map, MAX_LOCAL_APIC))
> > > +			continue;
> > > +
> > > +		/*
> > > +		 * If the bitmap cannot be listed in a buffer of length
> > > +		 * APICID_LIST_LEN, then it is suffixed with "...".
> > > +		 */
> > > +		len = bitmap_scnlistprintf(apicid_list, APICID_LIST_LEN,
> > > +					   apicid_map, MAX_LOCAL_APIC);
> > > +		pr_info("SRAT: PXM %u -> APIC {%s%s} -> Node %u\n",
> > > +			i, apicid_list,
> > > +			(len == APICID_LIST_LEN - 1) ? "..." : "",
> > > +			nid);
> > > +	}
> > >  }
> > 
> > No. As i suggested many times before, just get rid of the printouts or 
> > make them boot-debug-flag dependent.
> > 
> 
> Hmm, so even if these were dependent on a kernel parameter, do you think 
> this patch would still be needed exactly as it is written?  In other 
> words, do you believe that Mark's system should really emit 1272 lines for 
> this data instead of the 40 with this patch?
> 
> I'm all for making this dependent on a kernel parameter, but it's a 
> seperate change than what this patch is addressing.  We need the apic 
> id mappings because they aren't exposed to userspace in any other way, 
> they need to exported somehow and this is a clear improvement to 
> reduce verbosity in the kernel log.
>
> So I really don't know what you're insisting here, you want this 
> compression to be accompanied by another patch which makes the call to 
> acpi_numa_print_srat_mapping() depend on a kernel parameter?  Or are 
> you saying we shouldn't compress it at all and Mike should just deal 
> with 1272 lines instead of 40?  Or are you saying we should export 
> this static information via sysfs?

There's two problems outlined in this discussion:

 A) too verbose bootup that is annoying with 64 CPUs and a show-stopper
    with 4096 CPUs.

 B) the ad-hoc nature of our topology enumeration. Some of it is in
    /sys, some of it is in printk logs. None really works well and 
    there's no structure in it.

The simplest solution for (A) is what i suggested a few mails ago: dont 
print the information by default, but allow (for trouble-shooting) 
purposes for it to be printed when a boot option is passed.

Problem (B), topology info enumeration of a successful bootup is a 
different matter. It should be exposed to user-space via proper /sys 
abstractions, not via ad-hoc printks. There's ongoing work in that area, 
from Andreas Hermann, with patches posted. hpa expressed the view there 
that topology structure should be expressed via a nice vfs abstraction - 
i share that opinion.

	Ingo

Re: [patch] x86: reduce srat verbosity in the kernel log

[David Rientjes]

On Fri, 13 Nov 2009, Ingo Molnar wrote:

> There's two problems outlined in this discussion:
> 
>  A) too verbose bootup that is annoying with 64 CPUs and a show-stopper
>     with 4096 CPUs.
> 
>  B) the ad-hoc nature of our topology enumeration. Some of it is in
>     /sys, some of it is in printk logs. None really works well and 
>     there's no structure in it.
> 
> The simplest solution for (A) is what i suggested a few mails ago: dont 
> print the information by default, but allow (for trouble-shooting) 
> purposes for it to be printed when a boot option is passed.
> 

Sigh, and even if that were done with a subsequent patch, you would still 
want to reduce the debugging output from 1272 lines to 40, just like my 
patch does without losing any information.  It's insane to emit 1272 
lines even if they are emitted only for a certain kernel parameter.  I'm 
sure we agree on that.

> Problem (B), topology info enumeration of a successful bootup is a 
> different matter. It should be exposed to user-space via proper /sys 
> abstractions, not via ad-hoc printks. There's ongoing work in that area, 
> from Andreas Hermann, with patches posted. hpa expressed the view there 
> that topology structure should be expressed via a nice vfs abstraction - 
> i share that opinion.
> 

Ingo, what do you want?

Your first criticism was that it should be limited only to a kernel 
parameter but now it seems like you're insisting that the printk's get 
removed completely and its exported via userspace.  Then what is the 
kernel parameter that you suggested for?

I'll leave the discussion with saying that if we still want to emit this 
information with a parameter, that you'll still need to merge my patch at 
some point to reduce the 1272 lines on Mark's system to 40.  I'm unsure 
why that isn't just merged right now since it's a clear improvement over 
the current behavior, but I'm not going to beat a dead horse.

Thanks.

Re: [patch] x86: reduce srat verbosity in the kernel log

[Ingo Molnar]

* David Rientjes <rientjes@google.com> wrote:

> On Fri, 13 Nov 2009, Ingo Molnar wrote:
> 
> > There's two problems outlined in this discussion:
> > 
> >  A) too verbose bootup that is annoying with 64 CPUs and a show-stopper
> >     with 4096 CPUs.
> > 
> >  B) the ad-hoc nature of our topology enumeration. Some of it is in
> >     /sys, some of it is in printk logs. None really works well and 
> >     there's no structure in it.
> > 
> > The simplest solution for (A) is what i suggested a few mails ago: dont 
> > print the information by default, but allow (for trouble-shooting) 
> > purposes for it to be printed when a boot option is passed.
> > 
> 
> Sigh, and even if that were done with a subsequent patch, you would 
> still want to reduce the debugging output from 1272 lines to 40, just 
> like my patch does without losing any information.  It's insane to 
> emit 1272 lines even if they are emitted only for a certain kernel 
> parameter.  I'm sure we agree on that.

For _debug_ output, we want it pretty simple. 1272 lines is nothing if 
it's only done for debugging/trouble-shooting.

Furthermore, if this _only_ gets used in the debug case, we want it 
simple for the pure reason that it's uncommon code. It might work now, 
but it might regress later without anyone noticing it - up to the point 
when someone might need it when it breaks in the worst possible moment.

We've been through this many times before and that's the core principle 
of all debug printout code: keep it simple.

> > Problem (B), topology info enumeration of a successful bootup is a 
> > different matter. It should be exposed to user-space via proper /sys 
> > abstractions, not via ad-hoc printks. There's ongoing work in that 
> > area, from Andreas Hermann, with patches posted. hpa expressed the 
> > view there that topology structure should be expressed via a nice 
> > vfs abstraction - i share that opinion.
> 
> Ingo, what do you want?

My goal is to accept good patches and to reject patches that are bad or 
not good enough.

> Your first criticism was that it should be limited only to a kernel 
> parameter but now it seems like you're insisting that the printk's get 
> removed completely and its exported via userspace.  Then what is the 
> kernel parameter that you suggested for?

Please read my mail. There's three usecases:

  - default bootup. We want no messages in the log.

  - troubleshooting bootup with a boot flag specified. (an existing
    example is apic=verbose) We want simple messages in that case and 
    obvious logic. (verbosity is not an overriding issue - we are 
    troubleshooting)

  - Successful bootup and we want to retrieve topology information for 
    the system. Using the boot logs for it is not the right channel - 
    /sys is.

Your patch is not a 'good enough' solution to either of these usecases, 
because:

  - In the default case it prints 40 lines more than it should.

  - In the troubleshooting case it provides the information but it is
    not a simple mechanism. (anything with state and a bitmap in it is 
    out pretty much - stick to simple printks, those are in the least 
    danger of regressing down the road. It's also less bloated in terms 
    of code. )

  - For extracing topology information kernel log messages is not 
    something that tools can rely on very well.

Thanks,

	Ingo

Re: [patch] x86: reduce srat verbosity in the kernel log

[Pavel Machek]

Hi!

> There's two problems outlined in this discussion:
> 
>  A) too verbose bootup that is annoying with 64 CPUs and a show-stopper
>     with 4096 CPUs.
> 
>  B) the ad-hoc nature of our topology enumeration. Some of it is in
>     /sys, some of it is in printk logs. None really works well and 
>     there's no structure in it.
> 
> The simplest solution for (A) is what i suggested a few mails ago: dont 
> print the information by default, but allow (for trouble-shooting) 
> purposes for it to be printed when a boot option is passed.

Well, yes, it is *simplest*, but is it best? Example printing 'cpus
0-31 stepping 3, cpus 32-63 stepping 4' seem rather convincing --such
info should be there by default and not after speciial option...
									Pavel
-- 
(english) http://www.livejournal.com/~pavelmachek
(cesky, pictures) http://atrey.karlin.mff.cuni.cz/~pavel/picture/horses/blog.html

Re: [patch] x86: reduce srat verbosity in the kernel log

[Mike Travis]

Pavel Machek wrote:
> Hi!
> 
>> There's two problems outlined in this discussion:
>>
>>  A) too verbose bootup that is annoying with 64 CPUs and a show-stopper
>>     with 4096 CPUs.
>>
>>  B) the ad-hoc nature of our topology enumeration. Some of it is in
>>     /sys, some of it is in printk logs. None really works well and 
>>     there's no structure in it.
>>
>> The simplest solution for (A) is what i suggested a few mails ago: dont 
>> print the information by default, but allow (for trouble-shooting) 
>> purposes for it to be printed when a boot option is passed.
> 
> Well, yes, it is *simplest*, but is it best? Example printing 'cpus
> 0-31 stepping 3, cpus 32-63 stepping 4' seem rather convincing --such
> info should be there by default and not after speciial option...
> 									Pavel

I think that Ingo had a point.  If it's printing a summary after the
all the cpu's boot, then it should also be available online, which in
this case it's in /proc/cpuinfo.

Ingo - was there anything left open on my last submission that I have
to deal with, to gain acceptance?

Thanks,
Mike

Re: [PATCH 0/7] Limit console output by suppressing repetitious messages

[Yinghai Lu]

On Thu, Nov 12, 2009 at 9:19 AM, Mike Travis <travis@sgi.com> wrote:
>
> Second version...

what is the boot time that you can spare your this patchset?

YH