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

-- 

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

-- 

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

-- 

[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");
 	}
 
 	/*

-- 

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

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

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

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

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

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

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] x86: reduce srat verbosity in the kernel log

[David Rientjes]

On Thu, 29 Oct 2009, Mike Travis wrote:

> I believe the disjointed ranges came from the hyperthread cpus..?  Which if
> true means there'll probably be as many distinct ranges as there are threads
> per core?
> 

Not necessarily, look at the first few lines of your new output:

	[    0.000000] SRAT: PXM 0 -> APIC {0-7,16-23} -> Node 0
	[    0.000000] SRAT: PXM 1 -> APIC {32-39,48-55} -> Node 1
	[    0.000000] SRAT: PXM 2 -> APIC {64-71,80-87} -> Node 2
	...

If those values are in hex, you have these apic id ranges:

	0x00-0x07, 0x10-0x17
	0x20-0x27, 0x30-0x37
	0x40-0x47, 0x50-0x57
	...

So it's most likely that each of the physical processors has eight logical 
processors (represented by the least significant three bits) and there are 
two physical processors (the more significant four bits) per node.

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

[Mike Travis]

David Rientjes wrote:
> On Wed, 28 Oct 2009, Mike Travis wrote:
> 
>>> I'm not saying it would be illegal, merely that it would be harm
>>> readability.  Based on how apic id's are formed from processor ids, though,
>>> I think we're really talking about an upper limit (128) that will never be
>>> reached.
>> We actually have many, many more than that by adding on some extra bits
>> to the CPU's apicid.  These select which blade in the system to target.
>>
> 
> Maybe I've been vague in my rationale for why this limit will probably 
> never be reached.  The way apic ids are constructed, with physical and 
> logical processor ids, it tends to lend itself to ranges where 
> bitmap_scnlistprintf() can specify a large number of apic ids with 
> relatively few ASCII characters because logical processors typically do 
> not have differing pxms.  For us to reach the 128 character upper bound, 
> scnlistprintf() would need to have many, many distinct ranges; your 
> example showed two ranges per pxm (many more machines would have only a 
> single range).  In other words, we're not predicting to have 
> "1-2,4-6,8-9,11-13,15-17," etc, that we often have with nodemasks.

Yes, you are correct.  (I was confused... ;-)

I believe the disjointed ranges came from the hyperthread cpus..?  Which if
true means there'll probably be as many distinct ranges as there are threads
per core?

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

[David Rientjes]

On Wed, 28 Oct 2009, Mike Travis wrote:

> > I'm not saying it would be illegal, merely that it would be harm
> > readability.  Based on how apic id's are formed from processor ids, though,
> > I think we're really talking about an upper limit (128) that will never be
> > reached.
> 
> We actually have many, many more than that by adding on some extra bits
> to the CPU's apicid.  These select which blade in the system to target.
> 

Maybe I've been vague in my rationale for why this limit will probably 
never be reached.  The way apic ids are constructed, with physical and 
logical processor ids, it tends to lend itself to ranges where 
bitmap_scnlistprintf() can specify a large number of apic ids with 
relatively few ASCII characters because logical processors typically do 
not have differing pxms.  For us to reach the 128 character upper bound, 
scnlistprintf() would need to have many, many distinct ranges; your 
example showed two ranges per pxm (many more machines would have only a 
single range).  In other words, we're not predicting to have 
"1-2,4-6,8-9,11-13,15-17," etc, that we often have with nodemasks.

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

[Mike Travis]

David Rientjes wrote:
> On Wed, 28 Oct 2009, Mike Travis wrote:
> 
>>> Printing a list of apic ids longer than 128 characters would pollute the
>>> kernel log and this upper bound will probably never be reached based on the
>>> way apic ids are created for physical and logical processors: they are
>>> normally reduced to ranges instead of comma seperated entities.
>> Ahh, ok, thanks.
>>
>> Does that mean this 10,649 character line full of periods is illegal?
>>
> 
> I'm not saying it would be illegal, merely that it would be harm 
> readability.  Based on how apic id's are formed from processor ids, 
> though, I think we're really talking about an upper limit (128) that will 
> never be reached.

We actually have many, many more than that by adding on some extra bits
to the CPU's apicid.  These select which blade in the system to target.

> 
>> [  102.551570] Completing Region/Field/Buffer/Package initialization:
>> ............... [long time later] .........
>> <4>Clocksource tsc unstable (delta = 4396383657849 ns)
>>
>> I'm having trouble finding it.  Does it look familiar to anyone?
>>
> 
> It's debugging output from acpi_ns_initialize_objects() and each period is 
> from acpi_ns_init_one_device().  You can suppress it by disabing 
> CONFIG_ACPI_DEBUG.

Ahh, didn't know that was set in the (our) default config.  Is it normally
set by distros?  

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

[David Rientjes]

On Wed, 28 Oct 2009, Mike Travis wrote:

> > Printing a list of apic ids longer than 128 characters would pollute the
> > kernel log and this upper bound will probably never be reached based on the
> > way apic ids are created for physical and logical processors: they are
> > normally reduced to ranges instead of comma seperated entities.
> 
> Ahh, ok, thanks.
> 
> Does that mean this 10,649 character line full of periods is illegal?
> 

I'm not saying it would be illegal, merely that it would be harm 
readability.  Based on how apic id's are formed from processor ids, 
though, I think we're really talking about an upper limit (128) that will 
never be reached.

> [  102.551570] Completing Region/Field/Buffer/Package initialization:
> ............... [long time later] .........
> <4>Clocksource tsc unstable (delta = 4396383657849 ns)
> 
> I'm having trouble finding it.  Does it look familiar to anyone?
> 

It's debugging output from acpi_ns_initialize_objects() and each period is 
from acpi_ns_init_one_device().  You can suppress it by disabing 
CONFIG_ACPI_DEBUG.

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

[Mike Travis]

David Rientjes wrote:
> On Wed, 28 Oct 2009, Mike Travis wrote:
> 
>> I don't understand the importance of this when the memory is given back
>> after the system starts up anyway...?
>>
> 
> Printing a list of apic ids longer than 128 characters would pollute the 
> kernel log and this upper bound will probably never be reached based on 
> the way apic ids are created for physical and logical processors: they are 
> normally reduced to ranges instead of comma seperated entities.

Ahh, ok, thanks.

Does that mean this 10,649 character line full of periods is illegal?

[  102.551570] Completing Region/Field/Buffer/Package initialization:
............... [long time later] .........
<4>Clocksource tsc unstable (delta = 4396383657849 ns)

I'm having trouble finding it.  Does it look familiar to anyone?

Thanks,
Mike

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

[David Rientjes]

On Wed, 28 Oct 2009, Mike Travis wrote:

> Your latest patch tested:
> 
> [    0.000000] SRAT: PXM 0 -> APIC {0-7,16-23} -> Node 0
> [    0.000000] SRAT: PXM 1 -> APIC {32-39,48-55} -> Node 1
> [    0.000000] SRAT: PXM 2 -> APIC {64-71,80-87} -> Node 2
> [    0.000000] SRAT: PXM 3 -> APIC {96-103,112-119} -> Node 3
> [    0.000000] SRAT: PXM 4 -> APIC {128-135,144-151} -> Node 4
> [    0.000000] SRAT: PXM 5 -> APIC {160-167,176-183} -> Node 5
> [    0.000000] SRAT: PXM 6 -> APIC {192-199,208-215} -> Node 6
> [    0.000000] SRAT: PXM 7 -> APIC {224-231,240-247} -> Node 7
> [    0.000000] SRAT: PXM 8 -> APIC {256-263,272-279} -> Node 8
> [    0.000000] SRAT: PXM 9 -> APIC {288-295,304-311} -> Node 9
> [    0.000000] SRAT: PXM 10 -> APIC {320-327,336-343} -> Node 10
> [    0.000000] SRAT: PXM 11 -> APIC {352-359,368-375} -> Node 11
> [    0.000000] SRAT: PXM 12 -> APIC {384-391,400-407} -> Node 12
> [    0.000000] SRAT: PXM 13 -> APIC {416-423,432-439} -> Node 13
> [    0.000000] SRAT: PXM 14 -> APIC {448-455,464-471} -> Node 14
> [    0.000000] SRAT: PXM 15 -> APIC {480-487,496-503} -> Node 15
> [    0.000000] SRAT: PXM 16 -> APIC {512-519,528-535} -> Node 16
> [    0.000000] SRAT: PXM 17 -> APIC {544-551,560-567} -> Node 17
> [    0.000000] SRAT: PXM 18 -> APIC {576-583,592-599} -> Node 18
> [    0.000000] SRAT: PXM 19 -> APIC {608-615,624-631} -> Node 19
> [    0.000000] SRAT: PXM 20 -> APIC {640-647,656-663} -> Node 20
> [    0.000000] SRAT: PXM 21 -> APIC {672-679,688-695} -> Node 21
> [    0.000000] SRAT: PXM 22 -> APIC {704-711,720-727} -> Node 22
> [    0.000000] SRAT: PXM 23 -> APIC {736-743,752-759} -> Node 23
> [    0.000000] SRAT: PXM 24 -> APIC {768-775,784-791} -> Node 24
> [    0.000000] SRAT: PXM 25 -> APIC {800-807,816-823} -> Node 25
> [    0.000000] SRAT: PXM 26 -> APIC {832-839,848-855} -> Node 26
> [    0.000000] SRAT: PXM 27 -> APIC {864-871,880-887} -> Node 27
> [    0.000000] SRAT: PXM 28 -> APIC {896-903,912-919} -> Node 28
> [    0.000000] SRAT: PXM 29 -> APIC {928-935,944-951} -> Node 29
> [    0.000000] SRAT: PXM 30 -> APIC {960-967,976-983} -> Node 30
> [    0.000000] SRAT: PXM 31 -> APIC {992-999,1008-1015} -> Node 31
> [    0.000000] SRAT: PXM 32 -> APIC {1024-1031,1040-1047} -> Node 32
> [    0.000000] SRAT: PXM 33 -> APIC {1056-1063,1072-1079} -> Node 33
> [    0.000000] SRAT: PXM 34 -> APIC {1088-1095,1104-1111} -> Node 34
> [    0.000000] SRAT: PXM 35 -> APIC {1120-1127,1136-1143} -> Node 35
> [    0.000000] SRAT: PXM 36 -> APIC {1152-1159,1168-1175} -> Node 36
> [    0.000000] SRAT: PXM 37 -> APIC {1184-1191,1200-1207} -> Node 37
> [    0.000000] SRAT: PXM 38 -> APIC {1216-1223,1232-1239} -> Node 38
> [    0.000000] SRAT: PXM 39 -> APIC {1248-1255,1264-1271} -> Node 39                                                                                             

Looks good, 1272 lines reduced to 40.

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

[Mike Travis]

David Rientjes wrote:
> On Wed, 28 Oct 2009, Mike Travis wrote:
> 
>> I don't understand the importance of this when the memory is given back
>> after the system starts up anyway...?
>>
> 
> Printing a list of apic ids longer than 128 characters would pollute the 
> kernel log and this upper bound will probably never be reached based on 
> the way apic ids are created for physical and logical processors: they are 
> normally reduced to ranges instead of comma seperated entities.

Your latest patch tested:

[    0.000000] SRAT: PXM 0 -> APIC {0-7,16-23} -> Node 0
[    0.000000] SRAT: PXM 1 -> APIC {32-39,48-55} -> Node 1
[    0.000000] SRAT: PXM 2 -> APIC {64-71,80-87} -> Node 2
[    0.000000] SRAT: PXM 3 -> APIC {96-103,112-119} -> Node 3
[    0.000000] SRAT: PXM 4 -> APIC {128-135,144-151} -> Node 4
[    0.000000] SRAT: PXM 5 -> APIC {160-167,176-183} -> Node 5
[    0.000000] SRAT: PXM 6 -> APIC {192-199,208-215} -> Node 6
[    0.000000] SRAT: PXM 7 -> APIC {224-231,240-247} -> Node 7
[    0.000000] SRAT: PXM 8 -> APIC {256-263,272-279} -> Node 8
[    0.000000] SRAT: PXM 9 -> APIC {288-295,304-311} -> Node 9
[    0.000000] SRAT: PXM 10 -> APIC {320-327,336-343} -> Node 10
[    0.000000] SRAT: PXM 11 -> APIC {352-359,368-375} -> Node 11
[    0.000000] SRAT: PXM 12 -> APIC {384-391,400-407} -> Node 12
[    0.000000] SRAT: PXM 13 -> APIC {416-423,432-439} -> Node 13
[    0.000000] SRAT: PXM 14 -> APIC {448-455,464-471} -> Node 14
[    0.000000] SRAT: PXM 15 -> APIC {480-487,496-503} -> Node 15
[    0.000000] SRAT: PXM 16 -> APIC {512-519,528-535} -> Node 16
[    0.000000] SRAT: PXM 17 -> APIC {544-551,560-567} -> Node 17
[    0.000000] SRAT: PXM 18 -> APIC {576-583,592-599} -> Node 18
[    0.000000] SRAT: PXM 19 -> APIC {608-615,624-631} -> Node 19
[    0.000000] SRAT: PXM 20 -> APIC {640-647,656-663} -> Node 20
[    0.000000] SRAT: PXM 21 -> APIC {672-679,688-695} -> Node 21
[    0.000000] SRAT: PXM 22 -> APIC {704-711,720-727} -> Node 22
[    0.000000] SRAT: PXM 23 -> APIC {736-743,752-759} -> Node 23
[    0.000000] SRAT: PXM 24 -> APIC {768-775,784-791} -> Node 24
[    0.000000] SRAT: PXM 25 -> APIC {800-807,816-823} -> Node 25
[    0.000000] SRAT: PXM 26 -> APIC {832-839,848-855} -> Node 26
[    0.000000] SRAT: PXM 27 -> APIC {864-871,880-887} -> Node 27
[    0.000000] SRAT: PXM 28 -> APIC {896-903,912-919} -> Node 28
[    0.000000] SRAT: PXM 29 -> APIC {928-935,944-951} -> Node 29
[    0.000000] SRAT: PXM 30 -> APIC {960-967,976-983} -> Node 30
[    0.000000] SRAT: PXM 31 -> APIC {992-999,1008-1015} -> Node 31
[    0.000000] SRAT: PXM 32 -> APIC {1024-1031,1040-1047} -> Node 32
[    0.000000] SRAT: PXM 33 -> APIC {1056-1063,1072-1079} -> Node 33
[    0.000000] SRAT: PXM 34 -> APIC {1088-1095,1104-1111} -> Node 34
[    0.000000] SRAT: PXM 35 -> APIC {1120-1127,1136-1143} -> Node 35
[    0.000000] SRAT: PXM 36 -> APIC {1152-1159,1168-1175} -> Node 36
[    0.000000] SRAT: PXM 37 -> APIC {1184-1191,1200-1207} -> Node 37
[    0.000000] SRAT: PXM 38 -> APIC {1216-1223,1232-1239} -> Node 38
[    0.000000] SRAT: PXM 39 -> APIC {1248-1255,1264-1271} -> Node 39                                                                                             

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

[David Rientjes]

On Wed, 28 Oct 2009, Mike Travis wrote:

> I don't understand the importance of this when the memory is given back
> after the system starts up anyway...?
> 

Printing a list of apic ids longer than 128 characters would pollute the 
kernel log and this upper bound will probably never be reached based on 
the way apic ids are created for physical and logical processors: they are 
normally reduced to ranges instead of comma seperated entities.

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

[Mike Travis]

Andi Kleen wrote:
>> MAX_LOCAL_APIC was definitely an arbitrary choice here and has very little 
>> relevance.  scnlistprintf will protect against overflow, but we still need 
>> to decide upon a constant that will emit the most information possible 
>> while not overly polluting the printk and saving on bss, as you mentioned.  
>> I suspect we could agree on a value as little as 128 and it would work for 
>> the overwhelming majority (all?) of users.
> 
> For now at least seems reasonable to limit to 128 or so yes (and go
> back to the stack). if we ever have sparse apic ids for nodes 
> then that might change; but in this case could still just do
> a acpidump or teach the printer to be more clever and support
> strides.
> 
> It would be just good to have some indication in the output
> if there was a overflow.
> 
> -Andi
> 

I don't understand the importance of this when the memory is given back
after the system starts up anyway...?

Thanks,
Mike

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

[Andi Kleen]

> > 
> 
> MAX_LOCAL_APIC was definitely an arbitrary choice here and has very little 
> relevance.  scnlistprintf will protect against overflow, but we still need 
> to decide upon a constant that will emit the most information possible 
> while not overly polluting the printk and saving on bss, as you mentioned.  
> I suspect we could agree on a value as little as 128 and it would work for 
> the overwhelming majority (all?) of users.

For now at least seems reasonable to limit to 128 or so yes (and go
back to the stack). if we ever have sparse apic ids for nodes 
then that might change; but in this case could still just do
a acpidump or teach the printer to be more clever and support
strides.

It would be just good to have some indication in the output
if there was a overflow.

-Andi

-- 
ak@linux.intel.com -- Speaking for myself only.

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

[David Rientjes]

On Tue, 27 Oct 2009, Yinghai Lu wrote:

> can you change the apic to hex print?
> 

That would be an extension made on top of my patch (which may be difficult 
without adding an additional library function to be used in this case 
since it relies on bitmap_scnlistprintf()).  It's been printed as an 
unsigned int for well over four years so I don't see any specific urgency, 
anyway.

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

[David Rientjes]

On Wed, 28 Oct 2009, Andi Kleen wrote:

> >> Quite the system you have there :)  What was once 760 lines has been 
> >> reduced to 24 without removing any information.
> >>
> >> This seems to be the most we can reduce this particular output since we 
> >> don't support mapping multiple pxms to a single node.
> >
> > Yes, thanks very much for the optimization.
> >
> > (And you can add my Acked-by or whatever you need.)
> 
> Looks also good to me, thanks. Also Acked-by.
> 

Thanks Andi.  I'm hoping Ingo will pick this up and not have a problem 
with the use of NUMA_NO_NODE vs. NID_INVAL since there's a patch pending 
in -mm that removes the former and this saves a Linus build error when he 
pushes for 2.6.33 (and they are both defined the same anyway).

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

[David Rientjes]

On Wed, 28 Oct 2009, Andi Kleen wrote:

> > +static DECLARE_BITMAP(apicid_map, MAX_LOCAL_APIC) __initdata;
> > +static char apicid_list[MAX_LOCAL_APIC] __initdata;
> 
> Is MAX_LOCAL_APIC really big enough to print them all in ASCII?
> 
> It would be better to not use that large a buffer, but print
> in smaller pieces (I realize this would enlarge your patch,
> but then it would also save a lot of BSS)
> 

MAX_LOCAL_APIC was definitely an arbitrary choice here and has very little 
relevance.  scnlistprintf will protect against overflow, but we still need 
to decide upon a constant that will emit the most information possible 
while not overly polluting the printk and saving on bss, as you mentioned.  
I suspect we could agree on a value as little as 128 and it would work for 
the overwhelming majority (all?) of users.

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

[Yinghai Lu]

David Rientjes wrote:
> On Tue, 27 Oct 2009, Mike Travis wrote:
> 
>> I applied your previous patch with the change to use static and
>> here's the console output from a live system:
>>
>>
>> [    0.000000] SRAT: PXM 0 -> APIC {0-7,16-23} -> Node 0
>> [    0.000000] SRAT: PXM 1 -> APIC {32-39,48-55} -> Node 1
>> [    0.000000] SRAT: PXM 2 -> APIC {64-71,80-87} -> Node 2
>> [    0.000000] SRAT: PXM 3 -> APIC {96-103,112-119} -> Node 3
>> [    0.000000] SRAT: PXM 4 -> APIC {128-135,144-151} -> Node 4
>> [    0.000000] SRAT: PXM 5 -> APIC {160-167,176-183} -> Node 5
>> [    0.000000] SRAT: PXM 6 -> APIC {192-199,208-215} -> Node 6
>> [    0.000000] SRAT: PXM 7 -> APIC {224-231,240-247} -> Node 7
>> [    0.000000] SRAT: PXM 8 -> APIC {256-263,272-279} -> Node 8
>> [    0.000000] SRAT: PXM 9 -> APIC {288-295,304-311} -> Node 9
>> [    0.000000] SRAT: PXM 10 -> APIC {320-327,336-343} -> Node 10
>> [    0.000000] SRAT: PXM 11 -> APIC {352-359,368-375} -> Node 11
>> [    0.000000] SRAT: PXM 12 -> APIC {384-391,400-407} -> Node 12
>> [    0.000000] SRAT: PXM 13 -> APIC {416-423,432-439} -> Node 13
>> [    0.000000] SRAT: PXM 14 -> APIC {448-455,464-471} -> Node 14
>> [    0.000000] SRAT: PXM 15 -> APIC {480-487,496-503} -> Node 15
>> [    0.000000] SRAT: PXM 16 -> APIC {512-519,528-535} -> Node 16
>> [    0.000000] SRAT: PXM 17 -> APIC {544-551,560-567} -> Node 17
>> [    0.000000] SRAT: PXM 18 -> APIC {576-583,592-599} -> Node 18
>> [    0.000000] SRAT: PXM 19 -> APIC {608-615,624-631} -> Node 19
>> [    0.000000] SRAT: PXM 20 -> APIC {640-647,656-663} -> Node 20
>> [    0.000000] SRAT: PXM 21 -> APIC {672-679,688-695} -> Node 21
>> [    0.000000] SRAT: PXM 22 -> APIC {704-711,720-727} -> Node 22
>> [    0.000000] SRAT: PXM 23 -> APIC {736-743,752-759} -> Node 23   
>>
> 
> Quite the system you have there :)  What was once 760 lines has been 
> reduced to 24 without removing any information.
> 

can you change the apic to hex print?

YH

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

[Andi Kleen]

> +static DECLARE_BITMAP(apicid_map, MAX_LOCAL_APIC) __initdata;
> +static char apicid_list[MAX_LOCAL_APIC] __initdata;

Is MAX_LOCAL_APIC really big enough to print them all in ASCII?

It would be better to not use that large a buffer, but print
in smaller pieces (I realize this would enlarge your patch,
but then it would also save a lot of BSS)

-Andi

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

[Andi Kleen]

>> Quite the system you have there :)  What was once 760 lines has been 
>> reduced to 24 without removing any information.
>>
>> This seems to be the most we can reduce this particular output since we 
>> don't support mapping multiple pxms to a single node.
>
> Yes, thanks very much for the optimization.
>
> (And you can add my Acked-by or whatever you need.)

Looks also good to me, thanks. Also Acked-by.

-Andi

-- 
ak@linux.intel.com -- Speaking for myself only.

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

[Mike Travis]

David Rientjes wrote:
> On Tue, 27 Oct 2009, Mike Travis wrote:
> 
>> I applied your previous patch with the change to use static and
>> here's the console output from a live system:
>>
>>
>> [    0.000000] SRAT: PXM 0 -> APIC {0-7,16-23} -> Node 0
>> [    0.000000] SRAT: PXM 1 -> APIC {32-39,48-55} -> Node 1
>> [    0.000000] SRAT: PXM 2 -> APIC {64-71,80-87} -> Node 2
>> [    0.000000] SRAT: PXM 3 -> APIC {96-103,112-119} -> Node 3
>> [    0.000000] SRAT: PXM 4 -> APIC {128-135,144-151} -> Node 4
>> [    0.000000] SRAT: PXM 5 -> APIC {160-167,176-183} -> Node 5
>> [    0.000000] SRAT: PXM 6 -> APIC {192-199,208-215} -> Node 6
>> [    0.000000] SRAT: PXM 7 -> APIC {224-231,240-247} -> Node 7
>> [    0.000000] SRAT: PXM 8 -> APIC {256-263,272-279} -> Node 8
>> [    0.000000] SRAT: PXM 9 -> APIC {288-295,304-311} -> Node 9
>> [    0.000000] SRAT: PXM 10 -> APIC {320-327,336-343} -> Node 10
>> [    0.000000] SRAT: PXM 11 -> APIC {352-359,368-375} -> Node 11
>> [    0.000000] SRAT: PXM 12 -> APIC {384-391,400-407} -> Node 12
>> [    0.000000] SRAT: PXM 13 -> APIC {416-423,432-439} -> Node 13
>> [    0.000000] SRAT: PXM 14 -> APIC {448-455,464-471} -> Node 14
>> [    0.000000] SRAT: PXM 15 -> APIC {480-487,496-503} -> Node 15
>> [    0.000000] SRAT: PXM 16 -> APIC {512-519,528-535} -> Node 16
>> [    0.000000] SRAT: PXM 17 -> APIC {544-551,560-567} -> Node 17
>> [    0.000000] SRAT: PXM 18 -> APIC {576-583,592-599} -> Node 18
>> [    0.000000] SRAT: PXM 19 -> APIC {608-615,624-631} -> Node 19
>> [    0.000000] SRAT: PXM 20 -> APIC {640-647,656-663} -> Node 20
>> [    0.000000] SRAT: PXM 21 -> APIC {672-679,688-695} -> Node 21
>> [    0.000000] SRAT: PXM 22 -> APIC {704-711,720-727} -> Node 22
>> [    0.000000] SRAT: PXM 23 -> APIC {736-743,752-759} -> Node 23   
>>
> 
> Quite the system you have there :)  What was once 760 lines has been 
> reduced to 24 without removing any information.
> 
> This seems to be the most we can reduce this particular output since we 
> don't support mapping multiple pxms to a single node.

Yes, thanks very much for the optimization.

(And you can add my Acked-by or whatever you need.)

Tomorrow I will have more time on the system and will try out all the
new changes together, mostly with summarizing the Processor stats.

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

[Cyrill Gorcunov]

[David Rientjes - Tue, Oct 27, 2009 at 02:06:21PM -0700]
| On Tue, 27 Oct 2009, Cyrill Gorcunov wrote:
| 
| > | +void __init acpi_numa_print_srat_mapping(void)
| > | +{
| > | +	int i, j;
| > | +
| > | +	for (i = 0; i < MAX_PXM_DOMAINS; i++) {
| > | +		int nid;
| > | +
| > | +		nid = pxm_to_node(i);
| > | +		if (nid == NUMA_NO_NODE)
| > 
| > Btw, David, while you at it, I just curious -- shouldn't we test it
| > with NID_INVAL (as pxm_to_node_map initially defined to)? Not a big
| > deal at all (since they are both = -1) but for the record.
| > Or perhaps I miss something?
| > 
| 
| I don't think we need to address that since NID_INVAL is going away and 
| will be replaced by NUMA_NO_NODE since Lee has exposed it globally in his 
| mempolicy patchset, and as you mention they are the same anyway.
| 

I see. Thanks!

	-- Cyrill

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

[David Rientjes]

On Tue, 27 Oct 2009, Cyrill Gorcunov wrote:

> | +void __init acpi_numa_print_srat_mapping(void)
> | +{
> | +	int i, j;
> | +
> | +	for (i = 0; i < MAX_PXM_DOMAINS; i++) {
> | +		int nid;
> | +
> | +		nid = pxm_to_node(i);
> | +		if (nid == NUMA_NO_NODE)
> 
> Btw, David, while you at it, I just curious -- shouldn't we test it
> with NID_INVAL (as pxm_to_node_map initially defined to)? Not a big
> deal at all (since they are both = -1) but for the record.
> Or perhaps I miss something?
> 

I don't think we need to address that since NID_INVAL is going away and 
will be replaced by NUMA_NO_NODE since Lee has exposed it globally in his 
mempolicy patchset, and as you mention they are the same anyway.

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

[Cyrill Gorcunov]

[David Rientjes - Tue, Oct 27, 2009 at 01:25:51PM -0700]
| On Tue, 27 Oct 2009, Mike Travis wrote:
| 
...
| +
| +void __init acpi_numa_print_srat_mapping(void)
| +{
| +	int i, j;
| +
| +	for (i = 0; i < MAX_PXM_DOMAINS; i++) {
| +		int nid;
| +
| +		nid = pxm_to_node(i);
| +		if (nid == NUMA_NO_NODE)

Btw, David, while you at it, I just curious -- shouldn't we test it
with NID_INVAL (as pxm_to_node_map initially defined to)? Not a big
deal at all (since they are both = -1) but for the record.
Or perhaps I miss something?

| +			continue;
...

	-- Cyrill

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

[David Rientjes]

On Tue, 27 Oct 2009, Mike Travis wrote:

> I applied your previous patch with the change to use static and
> here's the console output from a live system:
> 
> 
> [    0.000000] SRAT: PXM 0 -> APIC {0-7,16-23} -> Node 0
> [    0.000000] SRAT: PXM 1 -> APIC {32-39,48-55} -> Node 1
> [    0.000000] SRAT: PXM 2 -> APIC {64-71,80-87} -> Node 2
> [    0.000000] SRAT: PXM 3 -> APIC {96-103,112-119} -> Node 3
> [    0.000000] SRAT: PXM 4 -> APIC {128-135,144-151} -> Node 4
> [    0.000000] SRAT: PXM 5 -> APIC {160-167,176-183} -> Node 5
> [    0.000000] SRAT: PXM 6 -> APIC {192-199,208-215} -> Node 6
> [    0.000000] SRAT: PXM 7 -> APIC {224-231,240-247} -> Node 7
> [    0.000000] SRAT: PXM 8 -> APIC {256-263,272-279} -> Node 8
> [    0.000000] SRAT: PXM 9 -> APIC {288-295,304-311} -> Node 9
> [    0.000000] SRAT: PXM 10 -> APIC {320-327,336-343} -> Node 10
> [    0.000000] SRAT: PXM 11 -> APIC {352-359,368-375} -> Node 11
> [    0.000000] SRAT: PXM 12 -> APIC {384-391,400-407} -> Node 12
> [    0.000000] SRAT: PXM 13 -> APIC {416-423,432-439} -> Node 13
> [    0.000000] SRAT: PXM 14 -> APIC {448-455,464-471} -> Node 14
> [    0.000000] SRAT: PXM 15 -> APIC {480-487,496-503} -> Node 15
> [    0.000000] SRAT: PXM 16 -> APIC {512-519,528-535} -> Node 16
> [    0.000000] SRAT: PXM 17 -> APIC {544-551,560-567} -> Node 17
> [    0.000000] SRAT: PXM 18 -> APIC {576-583,592-599} -> Node 18
> [    0.000000] SRAT: PXM 19 -> APIC {608-615,624-631} -> Node 19
> [    0.000000] SRAT: PXM 20 -> APIC {640-647,656-663} -> Node 20
> [    0.000000] SRAT: PXM 21 -> APIC {672-679,688-695} -> Node 21
> [    0.000000] SRAT: PXM 22 -> APIC {704-711,720-727} -> Node 22
> [    0.000000] SRAT: PXM 23 -> APIC {736-743,752-759} -> Node 23   
> 

Quite the system you have there :)  What was once 760 lines has been 
reduced to 24 without removing any information.

This seems to be the most we can reduce this particular output since we 
don't support mapping multiple pxms to a single node.

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

[Mike Travis]

I applied your previous patch with the change to use static and
here's the console output from a live system:


[    0.000000] SRAT: PXM 0 -> APIC {0-7,16-23} -> Node 0
[    0.000000] SRAT: PXM 1 -> APIC {32-39,48-55} -> Node 1
[    0.000000] SRAT: PXM 2 -> APIC {64-71,80-87} -> Node 2
[    0.000000] SRAT: PXM 3 -> APIC {96-103,112-119} -> Node 3
[    0.000000] SRAT: PXM 4 -> APIC {128-135,144-151} -> Node 4
[    0.000000] SRAT: PXM 5 -> APIC {160-167,176-183} -> Node 5
[    0.000000] SRAT: PXM 6 -> APIC {192-199,208-215} -> Node 6
[    0.000000] SRAT: PXM 7 -> APIC {224-231,240-247} -> Node 7
[    0.000000] SRAT: PXM 8 -> APIC {256-263,272-279} -> Node 8
[    0.000000] SRAT: PXM 9 -> APIC {288-295,304-311} -> Node 9
[    0.000000] SRAT: PXM 10 -> APIC {320-327,336-343} -> Node 10
[    0.000000] SRAT: PXM 11 -> APIC {352-359,368-375} -> Node 11
[    0.000000] SRAT: PXM 12 -> APIC {384-391,400-407} -> Node 12
[    0.000000] SRAT: PXM 13 -> APIC {416-423,432-439} -> Node 13
[    0.000000] SRAT: PXM 14 -> APIC {448-455,464-471} -> Node 14
[    0.000000] SRAT: PXM 15 -> APIC {480-487,496-503} -> Node 15
[    0.000000] SRAT: PXM 16 -> APIC {512-519,528-535} -> Node 16
[    0.000000] SRAT: PXM 17 -> APIC {544-551,560-567} -> Node 17
[    0.000000] SRAT: PXM 18 -> APIC {576-583,592-599} -> Node 18
[    0.000000] SRAT: PXM 19 -> APIC {608-615,624-631} -> Node 19
[    0.000000] SRAT: PXM 20 -> APIC {640-647,656-663} -> Node 20
[    0.000000] SRAT: PXM 21 -> APIC {672-679,688-695} -> Node 21
[    0.000000] SRAT: PXM 22 -> APIC {704-711,720-727} -> Node 22
[    0.000000] SRAT: PXM 23 -> APIC {736-743,752-759} -> Node 23   

                                                                                              
David Rientjes wrote:
> On Tue, 27 Oct 2009, Mike Travis wrote:
> 
>> Hi David,
>>
>> Very Cool, I'll try it out and let you know how it goes.
>>
>> Note that it would be better to declare the BITMAP in the
>> static initdata section so it doesn't grow the stack by 4k
>> bytes.  (And it's thrown away after the kernel starts.)
>>
> 
> Right, here's an updated version.  I was thinking of MAX_PXM_DOMAINS being 
> 256 instead of MAX_LOCAL_APIC :)
> 
> Here's an updated version.  apicid_map and apicid_list don't need to be 
> synchronized because there're no concurrency issues here on init.
> 
> 
> 
> x86: reduce srat verbosity in the kernel log
> 
> 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 apicids 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
> 
> Signed-off-by: David Rientjes <rientjes@google.com>
> ---
>  arch/x86/mm/srat_64.c |   32 ++++++++++++++++++++++++++++----
>  drivers/acpi/numa.c   |    5 +++++
>  include/linux/acpi.h  |    3 ++-
>  3 files changed, 35 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;
> +static char apicid_list[MAX_LOCAL_APIC] __initdata;
> +
>  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,31 @@ 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)
> +{
> +	int i, j;
> +
> +	for (i = 0; i < MAX_PXM_DOMAINS; i++) {
> +		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;
> +		bitmap_scnlistprintf(apicid_list, MAX_LOCAL_APIC,
> +				     apicid_map, MAX_LOCAL_APIC);
> +		pr_info("SRAT: PXM %u -> APIC {%s} -> Node %u\n",
> +			i, apicid_list, 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 */

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

[David Rientjes]

On Tue, 27 Oct 2009, Mike Travis wrote:

> Hi David,
> 
> Very Cool, I'll try it out and let you know how it goes.
> 
> Note that it would be better to declare the BITMAP in the
> static initdata section so it doesn't grow the stack by 4k
> bytes.  (And it's thrown away after the kernel starts.)
> 

Right, here's an updated version.  I was thinking of MAX_PXM_DOMAINS being 
256 instead of MAX_LOCAL_APIC :)

Here's an updated version.  apicid_map and apicid_list don't need to be 
synchronized because there're no concurrency issues here on init.



x86: reduce srat verbosity in the kernel log

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

Signed-off-by: David Rientjes <rientjes@google.com>
---
 arch/x86/mm/srat_64.c |   32 ++++++++++++++++++++++++++++----
 drivers/acpi/numa.c   |    5 +++++
 include/linux/acpi.h  |    3 ++-
 3 files changed, 35 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;
+static char apicid_list[MAX_LOCAL_APIC] __initdata;
+
 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,31 @@ 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)
+{
+	int i, j;
+
+	for (i = 0; i < MAX_PXM_DOMAINS; i++) {
+		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;
+		bitmap_scnlistprintf(apicid_list, MAX_LOCAL_APIC,
+				     apicid_map, MAX_LOCAL_APIC);
+		pr_info("SRAT: PXM %u -> APIC {%s} -> Node %u\n",
+			i, apicid_list, 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 */