[PATCH 0/5] init: Shrink early messages to prevent overflowing the kernel log buffer

[PATCH 0/5] init: Shrink early messages to prevent overflowing the kernel log buffer

[Mike Travis]

v2: updated to apply to x86-tip

On larger systems, information in the kernel log is lost because
there is so much early text printed, that it overflows the static
log buffer before the log_buf_len kernel parameter can be processed,
and a bigger log buffer allocated.

Distros are relunctant to increase memory usage by increasing the
size of the static log buffer, so minimize the problem by allocating
the new log buffer as early as possible, and reducing the amount
of characters those early messages generate.

Some stats from testing these changes on our current lab UV systems.
(Both of these systems lost all of the e820 and EFI memmap ranges
before the changes.)

System X:
	8,793,945,145,344 bytes of system memory
	256 nodes
	599 EFI Mem ranges
	4096 cpu_ids
	43% of static log buffer unused

System Y:
	11,779,115,188,224 bytes of system memory
	492 Nodes
	976 EFI Mem ranges
	1968 cpu_ids
	17% of static log buffer unused

The last stat is how close the static log buffer came
to overflowing.  While these resources are fairly close
to today's max limits, there is not a lot of head room
for growth.

An alternative for the future might be to create a larger
static log buffer in the __initdata section, and then
always allocate a dynamically sized log buffer to replace
it.  This would also allow shrinking the log buffer for
memory tight situations.  But it would add complexity to
the code.

-- 

[PATCH 1/5] ACPI: Minimize X2APIC initial messages

[Mike Travis]

[-- Attachment #1: minimize-x2apic-msgs --]
[-- Type: text/plain, Size: 1599 bytes --]

Minimize X2APIC messages by printing 8 per line and dropping
the "enabled" flag since that's assumed.  It will still print
"disabled" if necessary.

v2: updated to apply to x86-tip

Signed-off-by: Mike Travis <travis@sgi.com>
Reviewed-by: Jack Steiner <steiner@sgi.com>
Reviewed-by: Robin Holt <holt@sgi.com>
---
 arch/x86/kernel/acpi/boot.c |    3 +++
 drivers/acpi/tables.c       |   13 +++++++++----
 2 files changed, 12 insertions(+), 4 deletions(-)

--- linux.orig/arch/x86/kernel/acpi/boot.c
+++ linux/arch/x86/kernel/acpi/boot.c
@@ -903,6 +903,9 @@ static int __init acpi_parse_madt_lapic_
 	if (!count) {
 		x2count = acpi_table_parse_madt(ACPI_MADT_TYPE_LOCAL_X2APIC,
 					acpi_parse_x2apic, MAX_LOCAL_APIC);
+		/* insure trailing newline is output */
+		pr_cont("\n");
+
 		count = acpi_table_parse_madt(ACPI_MADT_TYPE_LOCAL_APIC,
 					acpi_parse_lapic, MAX_LOCAL_APIC);
 	}
--- linux.orig/drivers/acpi/tables.c
+++ linux/drivers/acpi/tables.c
@@ -66,11 +66,16 @@ void acpi_table_print_madt_entry(struct
 		{
 			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",
+
+			if ((p->uid & 7) == 0)
+				pr_info(PREFIX "X2APIC apic_id=uid:");
+
+			pr_cont(" %02x=%02x%s%s",
 			       p->local_apic_id, p->uid,
-			       (p->lapic_flags & ACPI_MADT_ENABLED) ?
-			       "enabled" : "disabled");
+			       /* assume "enabled" unless "disabled" */
+				(p->lapic_flags & ACPI_MADT_ENABLED) ?
+				"" : " disabled",
+				(p->uid & 7) == 7 ? "\n" : "");
 		}
 		break;
 

-- 

[PATCH 2/5] x86: Minimize initial e820 messages

[Mike Travis]

[-- Attachment #1: minimize-e820-msgs --]
[-- Type: text/plain, Size: 6977 bytes --]

Minimize the early e820 messages by printing less characters
for the address range as well as abbreviating the type info
for each entry.

Also the "modified physical RAM map" was mostly a duplicate of
the original e820 memory map printout.  Minimize the output
by only printing those entries that were actually modified.

v1: Added pertinent __init & __initdata specifiers
    Changed some inlines to __init functions to avoid the
    the compiler un-inlining them into the wrong section.

v2: updated to apply to x86-tip

Signed-off-by: Mike Travis <travis@sgi.com>
Reviewed-by: Jack Steiner <steiner@sgi.com>
Reviewed-by: Robin Holt <holt@sgi.com>
---
 arch/x86/kernel/e820.c      |  133 ++++++++++++++++++++++++++------------------
 arch/x86/platform/efi/efi.c |   10 +--
 2 files changed, 86 insertions(+), 57 deletions(-)

--- linux.orig/arch/x86/kernel/e820.c
+++ linux/arch/x86/kernel/e820.c
@@ -38,6 +38,8 @@
  */
 struct e820map e820;
 struct e820map e820_saved;
+struct e820map e820_prev __initdata;
+int e820_prev_saved __initdata;
 
 /* For PCI or other memory-mapped resources */
 unsigned long pci_mem_start = 0xaeedbabe;
@@ -125,42 +127,85 @@ void __init e820_add_region(u64 start, u
 	__e820_add_region(&e820, start, size, type);
 }
 
-static void __init e820_print_type(u32 type)
+/* long description */
+static const char * __init e820_type_to_string(int e820_type)
 {
-	switch (type) {
-	case E820_RAM:
-	case E820_RESERVED_KERN:
-		printk(KERN_CONT "(usable)");
-		break;
-	case E820_RESERVED:
-		printk(KERN_CONT "(reserved)");
-		break;
-	case E820_ACPI:
-		printk(KERN_CONT "(ACPI data)");
-		break;
-	case E820_NVS:
-		printk(KERN_CONT "(ACPI NVS)");
-		break;
-	case E820_UNUSABLE:
-		printk(KERN_CONT "(unusable)");
-		break;
-	default:
-		printk(KERN_CONT "type %u", type);
-		break;
+	switch (e820_type) {
+	case E820_RESERVED_KERN:	return "Kernel RAM";
+	case E820_RAM:	return "System RAM";
+	case E820_ACPI:	return "ACPI Tables";
+	case E820_NVS:	return "ACPI Non-Volatile Storage";
+	case E820_UNUSABLE:	return "Unusable Memory";
+	default:	return "Reserved";
+	}
+}
+
+/* short description, saves log space when there are 100's of e820 entries */
+static char * __init e820_types(int e820_type)
+{
+	switch (e820_type) {
+	case E820_RESERVED_KERN:	return "KRAM";
+	case E820_RAM:	return "SRAM";
+	case E820_ACPI:	return "ACPI";
+	case E820_NVS:	return "NVS"";
+	case E820_UNUSABLE:	return "UM";
+	default:	return "RESVD";
+	}
+}
+
+static void __init e820_print_header(void)
+{
+	pr_info("types: %s=(%s) %s=(%s) %s=(%s) %s=(%s) %s=(%s) %s=(%s)\n",
+		e820_types(E820_RESERVED_KERN),
+				e820_type_to_string(E820_RESERVED_KERN),
+		e820_types(E820_RAM), e820_type_to_string(E820_RAM),
+		e820_types(E820_RESERVED), e820_type_to_string(E820_RESERVED),
+		e820_types(E820_ACPI), e820_type_to_string(E820_ACPI),
+		e820_types(E820_NVS), e820_type_to_string(E820_NVS),
+		e820_types(E820_UNUSABLE), e820_type_to_string(E820_UNUSABLE));
+}
+
+/* compare new entry with old so we only print "modified" entries */
+static int __init not_modified(int i, int j)
+{
+	for (; j < e820_prev.nr_map &&
+		e820_prev.map[j].addr <= e820.map[i].addr; j++) {
+
+		if (e820.map[i].addr == e820_prev.map[j].addr &&
+		    e820.map[i].size == e820_prev.map[j].size &&
+		    e820.map[i].type == e820_prev.map[j].type)
+			return j;
 	}
+	return 0;
 }
 
 void __init e820_print_map(char *who)
 {
-	int i;
+	int i, j = 0;
+	int hdr = 0;
+	int mod = strcmp(who, "modified") == 0;
 
 	for (i = 0; i < e820.nr_map; i++) {
-		printk(KERN_INFO " %s: %016Lx - %016Lx ", who,
-		       (unsigned long long) e820.map[i].addr,
-		       (unsigned long long)
-		       (e820.map[i].addr + e820.map[i].size));
-		e820_print_type(e820.map[i].type);
-		printk(KERN_CONT "\n");
+		/* only print those entries that were really modified */
+		if (mod)
+			j = not_modified(i, j);
+
+		if (!j) {
+			if (!hdr++)
+				e820_print_header();
+
+			pr_info("%s: %Lx+%Lx (%d)\n", who,
+			       (unsigned long long) e820.map[i].addr,
+			       (unsigned long long) e820.map[i].size,
+			       e820_types[e820.map[i].type]);
+		}
+	}
+	if (!hdr)
+		pr_info("<none>\n");
+
+	if (!e820_prev_saved) {
+		memcpy(&e820_prev, &e820, sizeof(struct e820map));
+		e820_prev_saved = 1;
 	}
 }
 
@@ -437,13 +482,11 @@ static u64 __init __e820_update_range(st
 		size = ULLONG_MAX - start;
 
 	end = start + size;
-	printk(KERN_DEBUG "e820 update range: %016Lx - %016Lx ",
+	pr_debug("e820 update range: %Lx+%Lx %s ==> %s\n",
 		       (unsigned long long) start,
-		       (unsigned long long) end);
-	e820_print_type(old_type);
-	printk(KERN_CONT " ==> ");
-	e820_print_type(new_type);
-	printk(KERN_CONT "\n");
+		       (unsigned long long) size,
+			e820_type_to_string(old_type),
+			e820_type_to_string(new_type));
 
 	for (i = 0; i < e820x->nr_map; i++) {
 		struct e820entry *ei = &e820x->map[i];
@@ -518,12 +561,10 @@ u64 __init e820_remove_range(u64 start,
 		size = ULLONG_MAX - start;
 
 	end = start + size;
-	printk(KERN_DEBUG "e820 remove range: %016Lx - %016Lx ",
+	printk(KERN_DEBUG "e820 remove range: %016Lx - %016Lx %s\n",
 		       (unsigned long long) start,
-		       (unsigned long long) end);
-	if (checktype)
-		e820_print_type(old_type);
-	printk(KERN_CONT "\n");
+		       (unsigned long long) end,
+			checktype ? e820_type_to_string(old_type) : "");
 
 	for (i = 0; i < e820.nr_map; i++) {
 		struct e820entry *ei = &e820.map[i];
@@ -576,7 +617,7 @@ void __init update_e820(void)
 	if (sanitize_e820_map(e820.map, ARRAY_SIZE(e820.map), &nr_map))
 		return;
 	e820.nr_map = nr_map;
-	printk(KERN_INFO "modified physical RAM map:\n");
+	printk(KERN_INFO "physical RAM map entries that were modified:\n");
 	e820_print_map("modified");
 }
 static void __init update_e820_saved(void)
@@ -926,18 +967,6 @@ void __init finish_e820_parsing(void)
 	}
 }
 
-static inline const char *e820_type_to_string(int e820_type)
-{
-	switch (e820_type) {
-	case E820_RESERVED_KERN:
-	case E820_RAM:	return "System RAM";
-	case E820_ACPI:	return "ACPI Tables";
-	case E820_NVS:	return "ACPI Non-volatile Storage";
-	case E820_UNUSABLE:	return "Unusable memory";
-	default:	return "reserved";
-	}
-}
-
 /*
  * Mark e820 reserved areas as busy for the resource manager.
  */
--- linux.orig/arch/x86/platform/efi/efi.c
+++ linux/arch/x86/platform/efi/efi.c
@@ -306,11 +306,11 @@ static void __init print_efi_memmap(void
 	     p < memmap.map_end;
 	     p += memmap.desc_size, i++) {
 		md = p;
-		printk(KERN_INFO PFX "mem%02u: type=%u, attr=0x%llx, "
-			"range=[0x%016llx-0x%016llx) (%lluMB)\n",
-			i, md->type, md->attribute, md->phys_addr,
-			md->phys_addr + (md->num_pages << EFI_PAGE_SHIFT),
-			(md->num_pages >> (20 - EFI_PAGE_SHIFT)));
+		pr_info(PFX
+			"mem%u: range %llx+%llx (%lluMB) type %u attr %llx\n",
+			i, md->phys_addr, md->num_pages << EFI_PAGE_SHIFT,
+			(md->num_pages >> (20 - EFI_PAGE_SHIFT)),
+			md->type, md->attribute);
 	}
 }
 #endif  /*  EFI_DEBUG  */

-- 

[PATCH 3/5] x86: Minimize SRAT messages

[Mike Travis]

[-- Attachment #1: minimize-srat-msgs.v2 --]
[-- Type: text/plain, Size: 2103 bytes --]

Condense the SRAT: messages to show all APIC id's for the
node on a single line.

v1: Added pertinent __init & __initdata specifiers.
v2: updated to apply to x86-tip

Signed-off-by: Mike Travis <travis@sgi.com>
Reviewed-by: Jack Steiner <steiner@sgi.com>
Reviewed-by: Robin Holt <holt@sgi.com>
---
 arch/x86/mm/srat_64.c |   16 ++++++++++++----
 drivers/acpi/numa.c   |    3 +++
 2 files changed, 15 insertions(+), 4 deletions(-)

--- linux.orig/arch/x86/mm/srat_64.c
+++ linux/arch/x86/mm/srat_64.c
@@ -116,6 +116,7 @@ acpi_numa_x2apic_affinity_init(struct ac
 {
 	int pxm, node;
 	int apic_id;
+	static int __initdata last_node = -1, last_pxm = -1;
 
 	if (srat_disabled())
 		return;
@@ -141,8 +142,16 @@ acpi_numa_x2apic_affinity_init(struct ac
 	set_apicid_to_node(apic_id, node);
 	node_set(node, cpu_nodes_parsed);
 	acpi_numa = 1;
-	printk(KERN_INFO "SRAT: PXM %u -> APIC 0x%04x -> Node %u\n",
-	       pxm, apic_id, node);
+	if (node != last_node) {
+		pr_info("SRAT: Node %u: PXM:APIC %u:%u",
+		       node, pxm, apic_id);
+		last_node = node;
+		last_pxm = pxm;
+	} else if (pxm != last_pxm) {
+		pr_cont(" %u:%u", pxm, apic_id);
+		last_pxm = pxm;
+	} else
+		pr_cont(" :%u", apic_id);
 }
 
 /* Callback for Proximity Domain -> LAPIC mapping */
@@ -301,8 +310,7 @@ acpi_numa_memory_affinity_init(struct ac
 			nd->end = end;
 	}
 
-	printk(KERN_INFO "SRAT: Node %u PXM %u %lx-%lx\n", node, pxm,
-	       start, end);
+	pr_info("SRAT: Node %u PXM %u %lx+%lx\n", node, pxm, start, end-start);
 
 	if (ma->flags & ACPI_SRAT_MEM_HOT_PLUGGABLE) {
 		update_nodes_add(node, start, end);
--- linux.orig/drivers/acpi/numa.c
+++ linux/drivers/acpi/numa.c
@@ -286,6 +286,9 @@ int __init acpi_numa_init(void)
 	if (!acpi_table_parse(ACPI_SIG_SRAT, acpi_parse_srat)) {
 		acpi_table_parse_srat(ACPI_SRAT_TYPE_X2APIC_CPU_AFFINITY,
 				     acpi_parse_x2apic_affinity, 0);
+		/* insure trailing newline is output */
+		pr_cont("\n");
+
 		acpi_table_parse_srat(ACPI_SRAT_TYPE_CPU_AFFINITY,
 				     acpi_parse_processor_affinity, 0);
 		ret = acpi_table_parse_srat(ACPI_SRAT_TYPE_MEMORY_AFFINITY,

-- 

[PATCH 4/5] printk: Minimize time zero output

[Mike Travis]

[-- Attachment #1: minimize-time-zero-msgs --]
[-- Type: text/plain, Size: 899 bytes --]

Reduce the length for time zero messages by only printing "[0] ".

v2: updated to apply to x86-tip

Signed-off-by: Mike Travis <travis@sgi.com>
Reviewed-by: Jack Steiner <steiner@sgi.com>
Reviewed-by: Robin Holt <holt@sgi.com>
---
 kernel/printk.c |    8 +++++---
 1 file changed, 5 insertions(+), 3 deletions(-)

--- linux.orig/kernel/printk.c
+++ linux/kernel/printk.c
@@ -818,11 +818,13 @@ asmlinkage int vprintk(const char *fmt,
 				unsigned long nanosec_rem;
 
 				t = cpu_clock(printk_cpu);
-				nanosec_rem = do_div(t, 1000000000);
-				tlen = sprintf(tbuf, "[%5lu.%06lu] ",
+				if (likely(t)) {
+					nanosec_rem = do_div(t, 1000000000);
+					tlen = sprintf(tbuf, "[%5lu.%06lu] ",
 						(unsigned long) t,
 						nanosec_rem / 1000);
-
+				} else
+					tlen = sprintf(tbuf, "[0] ");
 				for (tp = tbuf; tp < tbuf + tlen; tp++)
 					emit_log_char(*tp);
 				printed_len += tlen;

-- 

[PATCH 5/5] printk: Allocate kernel log buffer earlier

[Mike Travis]

[-- Attachment #1: get_log_buff_early --]
[-- Type: text/plain, Size: 4338 bytes --]

On larger systems, because of the numerous ACPI, Bootmem and EFI
messages, the static log buffer overflows before the larger one
specified by the log_buf_len param is allocated.  Minimize the
overflow by allocating the new log buffer as soon as possible.

All arch's are covered by the "setup_log_buf" in start_kernel().
The x86 arch allocates it right after bootmem is created.

v1: Added pertinent __init & __initdata specifiers.
v2: updated to apply to x86-tip

Signed-off-by: Mike Travis <travis@sgi.com>
Reviewed-by: Jack Steiner <steiner@sgi.com>
Reviewed-by: Robin Holt <holt@sgi.com>
---
 arch/x86/kernel/setup.c |    5 ++
 include/linux/printk.h  |    4 ++
 init/main.c             |    1 
 kernel/printk.c         |   81 +++++++++++++++++++++++++++++-------------------
 4 files changed, 60 insertions(+), 31 deletions(-)

--- linux.orig/arch/x86/kernel/setup.c
+++ linux/arch/x86/kernel/setup.c
@@ -1007,6 +1007,11 @@ void __init setup_arch(char **cmdline_p)
 	memblock_find_dma_reserve();
 	dma32_reserve_bootmem();
 
+	/*
+	 * Allocate bigger log buffer as early as possible
+	 */
+	setup_log_buf();
+
 #ifdef CONFIG_KVM_CLOCK
 	kvmclock_init();
 #endif
--- linux.orig/include/linux/printk.h
+++ linux/include/linux/printk.h
@@ -1,6 +1,8 @@
 #ifndef __KERNEL_PRINTK__
 #define __KERNEL_PRINTK__
 
+#include <linux/init.h>
+
 extern const char linux_banner[];
 extern const char linux_proc_banner[];
 
@@ -89,6 +91,8 @@ int no_printk(const char *fmt, ...)
 extern asmlinkage __attribute__ ((format (printf, 1, 2)))
 void early_printk(const char *fmt, ...);
 
+void __init setup_log_buf(void);
+
 extern int printk_needs_cpu(int cpu);
 extern void printk_tick(void);
 
--- linux.orig/init/main.c
+++ linux/init/main.c
@@ -592,6 +592,7 @@ asmlinkage void __init start_kernel(void
 	 * These use large bootmem allocations and must precede
 	 * kmem_cache_init()
 	 */
+	setup_log_buf();
 	pidhash_init();
 	vfs_caches_init_early();
 	sort_main_extable();
--- linux.orig/kernel/printk.c
+++ linux/kernel/printk.c
@@ -162,46 +162,65 @@ void log_buf_kexec_setup(void)
 }
 #endif
 
+static unsigned long __initdata new_log_buf_len;
 static int __init log_buf_len_setup(char *str)
 {
 	unsigned size = memparse(str, &str);
-	unsigned long flags;
 
 	if (size)
 		size = roundup_pow_of_two(size);
-	if (size > log_buf_len) {
-		unsigned start, dest_idx, offset;
-		char *new_log_buf;
-
-		new_log_buf = alloc_bootmem(size);
-		if (!new_log_buf) {
-			printk(KERN_WARNING "log_buf_len: allocation failed\n");
-			goto out;
-		}
-
-		spin_lock_irqsave(&logbuf_lock, flags);
-		log_buf_len = size;
-		log_buf = new_log_buf;
-
-		offset = start = min(con_start, log_start);
-		dest_idx = 0;
-		while (start != log_end) {
-			log_buf[dest_idx] = __log_buf[start & (__LOG_BUF_LEN - 1)];
-			start++;
-			dest_idx++;
-		}
-		log_start -= offset;
-		con_start -= offset;
-		log_end -= offset;
-		spin_unlock_irqrestore(&logbuf_lock, flags);
+	if (size > log_buf_len)
+		new_log_buf_len = size;
 
-		printk(KERN_NOTICE "log_buf_len: %d\n", log_buf_len);
-	}
-out:
-	return 1;
+	return 0;
 }
+early_param("log_buf_len", log_buf_len_setup);
 
-__setup("log_buf_len=", log_buf_len_setup);
+void __init setup_log_buf(void)
+{
+	unsigned long flags;
+	unsigned start, dest_idx, offset;
+	char *new_log_buf;
+	char first_line[64], *first_nl;
+
+	if (!new_log_buf_len)
+		return;
+
+	new_log_buf = alloc_bootmem(new_log_buf_len);
+	memset(first_line, 0, sizeof(first_line));
+
+	spin_lock_irqsave(&logbuf_lock, flags);
+	log_buf_len = new_log_buf_len;
+	log_buf = new_log_buf;
+	new_log_buf_len = 0;
+
+	offset = start = min(con_start, log_start);
+	dest_idx = 0;
+	while (start != log_end) {
+		unsigned log_idx_mask = start & (__LOG_BUF_LEN - 1);
+
+		log_buf[dest_idx] = __log_buf[log_idx_mask];
+		if (dest_idx < sizeof(first_line) - 1)
+			first_line[dest_idx] = __log_buf[log_idx_mask];
+		start++;
+		dest_idx++;
+	}
+	log_start -= offset;
+	con_start -= offset;
+	log_end -= offset;
+	spin_unlock_irqrestore(&logbuf_lock, flags);
+
+	first_nl = strchr(first_line, '\n');
+	if (first_nl)
+		*first_nl = '\0';
+
+	pr_info("log_buf_len: %d, first line: %s\n",
+		log_buf_len, first_line);
+
+	pr_debug("bu: %d/%d (%d%%)\n",
+		dest_idx, __LOG_BUF_LEN - dest_idx,
+		(dest_idx * 100) / __LOG_BUF_LEN);
+}
 
 #ifdef CONFIG_BOOT_PRINTK_DELAY
 

-- 

Re: [PATCH 5/5] printk: Allocate kernel log buffer earlier

[Yinghai Lu]

On Thu, Feb 17, 2011 at 10:51 AM, Mike Travis <travis@sgi.com> wrote:
> On larger systems, because of the numerous ACPI, Bootmem and EFI
> messages, the static log buffer overflows before the larger one
> specified by the log_buf_len param is allocated.  Minimize the
> overflow by allocating the new log buffer as soon as possible.
>
> All arch's are covered by the "setup_log_buf" in start_kernel().
> The x86 arch allocates it right after bootmem is created.
>
> v1: Added pertinent __init & __initdata specifiers.
> v2: updated to apply to x86-tip
>
> Signed-off-by: Mike Travis <travis@sgi.com>
> Reviewed-by: Jack Steiner <steiner@sgi.com>
> Reviewed-by: Robin Holt <holt@sgi.com>
> ---
>  arch/x86/kernel/setup.c |    5 ++
>  include/linux/printk.h  |    4 ++
>  init/main.c             |    1
>  kernel/printk.c         |   81 +++++++++++++++++++++++++++++-------------------
>  4 files changed, 60 insertions(+), 31 deletions(-)
>
> --- linux.orig/arch/x86/kernel/setup.c
> +++ linux/arch/x86/kernel/setup.c
> @@ -1007,6 +1007,11 @@ void __init setup_arch(char **cmdline_p)
>        memblock_find_dma_reserve();
>        dma32_reserve_bootmem();
>
> +       /*
> +        * Allocate bigger log buffer as early as possible
> +        */
> +       setup_log_buf();
> +
>  #ifdef CONFIG_KVM_CLOCK
>        kvmclock_init();
>  #endif
> --- linux.orig/include/linux/printk.h
> +++ linux/include/linux/printk.h
> @@ -1,6 +1,8 @@
>  #ifndef __KERNEL_PRINTK__
>  #define __KERNEL_PRINTK__
>
> +#include <linux/init.h>
> +
>  extern const char linux_banner[];
>  extern const char linux_proc_banner[];
>
> @@ -89,6 +91,8 @@ int no_printk(const char *fmt, ...)
>  extern asmlinkage __attribute__ ((format (printf, 1, 2)))
>  void early_printk(const char *fmt, ...);
>
> +void __init setup_log_buf(void);
> +
>  extern int printk_needs_cpu(int cpu);
>  extern void printk_tick(void);
>
> --- linux.orig/init/main.c
> +++ linux/init/main.c
> @@ -592,6 +592,7 @@ asmlinkage void __init start_kernel(void
>         * These use large bootmem allocations and must precede
>         * kmem_cache_init()
>         */
> +       setup_log_buf();
>        pidhash_init();
>        vfs_caches_init_early();
>        sort_main_extable();
> --- linux.orig/kernel/printk.c
> +++ linux/kernel/printk.c
> @@ -162,46 +162,65 @@ void log_buf_kexec_setup(void)
>  }
>  #endif
>
> +static unsigned long __initdata new_log_buf_len;
>  static int __init log_buf_len_setup(char *str)
>  {
>        unsigned size = memparse(str, &str);
> -       unsigned long flags;
>
>        if (size)
>                size = roundup_pow_of_two(size);
> -       if (size > log_buf_len) {
> -               unsigned start, dest_idx, offset;
> -               char *new_log_buf;
> -
> -               new_log_buf = alloc_bootmem(size);
> -               if (!new_log_buf) {
> -                       printk(KERN_WARNING "log_buf_len: allocation failed\n");
> -                       goto out;
> -               }
> -
> -               spin_lock_irqsave(&logbuf_lock, flags);
> -               log_buf_len = size;
> -               log_buf = new_log_buf;
> -
> -               offset = start = min(con_start, log_start);
> -               dest_idx = 0;
> -               while (start != log_end) {
> -                       log_buf[dest_idx] = __log_buf[start & (__LOG_BUF_LEN - 1)];
> -                       start++;
> -                       dest_idx++;
> -               }
> -               log_start -= offset;
> -               con_start -= offset;
> -               log_end -= offset;
> -               spin_unlock_irqrestore(&logbuf_lock, flags);
> +       if (size > log_buf_len)
> +               new_log_buf_len = size;
>
> -               printk(KERN_NOTICE "log_buf_len: %d\n", log_buf_len);
> -       }
> -out:
> -       return 1;
> +       return 0;
>  }
> +early_param("log_buf_len", log_buf_len_setup);
>
> -__setup("log_buf_len=", log_buf_len_setup);
> +void __init setup_log_buf(void)
> +{
> +       unsigned long flags;
> +       unsigned start, dest_idx, offset;
> +       char *new_log_buf;
> +       char first_line[64], *first_nl;
> +
> +       if (!new_log_buf_len)
> +               return;
> +
> +       new_log_buf = alloc_bootmem(new_log_buf_len);
> +       memset(first_line, 0, sizeof(first_line));

use x86_memblock_find_range in x86 code?

you can do that much earlier before SRAT etc is parsed.

Thanks

Yinghai
--
To unsubscribe from this list: send the line "unsubscribe linux-acpi" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [PATCH 5/5] printk: Allocate kernel log buffer earlier

[Yinghai Lu]

On Thu, Feb 17, 2011 at 10:51 AM, Mike Travis <travis@sgi.com> wrote:
> On larger systems, because of the numerous ACPI, Bootmem and EFI
> messages, the static log buffer overflows before the larger one
> specified by the log_buf_len param is allocated.  Minimize the
> overflow by allocating the new log buffer as soon as possible.
>
> All arch's are covered by the "setup_log_buf" in start_kernel().
> The x86 arch allocates it right after bootmem is created.
>
> v1: Added pertinent __init & __initdata specifiers.
> v2: updated to apply to x86-tip
>
> Signed-off-by: Mike Travis <travis@sgi.com>
> Reviewed-by: Jack Steiner <steiner@sgi.com>
> Reviewed-by: Robin Holt <holt@sgi.com>
> ---
>  arch/x86/kernel/setup.c |    5 ++
>  include/linux/printk.h  |    4 ++
>  init/main.c             |    1
>  kernel/printk.c         |   81 +++++++++++++++++++++++++++++-------------------
>  4 files changed, 60 insertions(+), 31 deletions(-)
>
> --- linux.orig/arch/x86/kernel/setup.c
> +++ linux/arch/x86/kernel/setup.c
> @@ -1007,6 +1007,11 @@ void __init setup_arch(char **cmdline_p)
>        memblock_find_dma_reserve();
>        dma32_reserve_bootmem();
>
> +       /*
> +        * Allocate bigger log buffer as early as possible
> +        */
> +       setup_log_buf();
> +
>  #ifdef CONFIG_KVM_CLOCK
>        kvmclock_init();
>  #endif
> --- linux.orig/include/linux/printk.h
> +++ linux/include/linux/printk.h
> @@ -1,6 +1,8 @@
>  #ifndef __KERNEL_PRINTK__
>  #define __KERNEL_PRINTK__
>
> +#include <linux/init.h>
> +
>  extern const char linux_banner[];
>  extern const char linux_proc_banner[];
>
> @@ -89,6 +91,8 @@ int no_printk(const char *fmt, ...)
>  extern asmlinkage __attribute__ ((format (printf, 1, 2)))
>  void early_printk(const char *fmt, ...);
>
> +void __init setup_log_buf(void);
> +
>  extern int printk_needs_cpu(int cpu);
>  extern void printk_tick(void);
>
> --- linux.orig/init/main.c
> +++ linux/init/main.c
> @@ -592,6 +592,7 @@ asmlinkage void __init start_kernel(void
>         * These use large bootmem allocations and must precede
>         * kmem_cache_init()
>         */
> +       setup_log_buf();
>        pidhash_init();
>        vfs_caches_init_early();
>        sort_main_extable();
> --- linux.orig/kernel/printk.c
> +++ linux/kernel/printk.c
> @@ -162,46 +162,65 @@ void log_buf_kexec_setup(void)
>  }
>  #endif
>
> +static unsigned long __initdata new_log_buf_len;
>  static int __init log_buf_len_setup(char *str)
>  {
>        unsigned size = memparse(str, &str);
> -       unsigned long flags;
>
>        if (size)
>                size = roundup_pow_of_two(size);
> -       if (size > log_buf_len) {
> -               unsigned start, dest_idx, offset;
> -               char *new_log_buf;
> -
> -               new_log_buf = alloc_bootmem(size);
> -               if (!new_log_buf) {
> -                       printk(KERN_WARNING "log_buf_len: allocation failed\n");
> -                       goto out;
> -               }
> -
> -               spin_lock_irqsave(&logbuf_lock, flags);
> -               log_buf_len = size;
> -               log_buf = new_log_buf;
> -
> -               offset = start = min(con_start, log_start);
> -               dest_idx = 0;
> -               while (start != log_end) {
> -                       log_buf[dest_idx] = __log_buf[start & (__LOG_BUF_LEN - 1)];
> -                       start++;
> -                       dest_idx++;
> -               }
> -               log_start -= offset;
> -               con_start -= offset;
> -               log_end -= offset;
> -               spin_unlock_irqrestore(&logbuf_lock, flags);
> +       if (size > log_buf_len)
> +               new_log_buf_len = size;
>
> -               printk(KERN_NOTICE "log_buf_len: %d\n", log_buf_len);
> -       }
> -out:
> -       return 1;
> +       return 0;
>  }
> +early_param("log_buf_len", log_buf_len_setup);
>
> -__setup("log_buf_len=", log_buf_len_setup);
> +void __init setup_log_buf(void)
> +{
> +       unsigned long flags;
> +       unsigned start, dest_idx, offset;
> +       char *new_log_buf;
> +       char first_line[64], *first_nl;
> +
> +       if (!new_log_buf_len)
> +               return;
> +
> +       new_log_buf = alloc_bootmem(new_log_buf_len);
> +       memset(first_line, 0, sizeof(first_line));

use x86_memblock_find_range in x86 code?

you can do that much earlier before SRAT etc is parsed.

Thanks

Yinghai

Re: [PATCH 5/5] printk: Allocate kernel log buffer earlier

[Mike Travis]

Yinghai Lu wrote:
> On Thu, Feb 17, 2011 at 10:51 AM, Mike Travis <travis@sgi.com> wrote:
>> On larger systems, because of the numerous ACPI, Bootmem and EFI
>> messages, the static log buffer overflows before the larger one
>> specified by the log_buf_len param is allocated.  Minimize the
>> overflow by allocating the new log buffer as soon as possible.
>>
>> All arch's are covered by the "setup_log_buf" in start_kernel().
>> The x86 arch allocates it right after bootmem is created.
>>
>> v1: Added pertinent __init & __initdata specifiers.
>> v2: updated to apply to x86-tip
>>
>> Signed-off-by: Mike Travis <travis@sgi.com>
>> Reviewed-by: Jack Steiner <steiner@sgi.com>
>> Reviewed-by: Robin Holt <holt@sgi.com>
>> ---
>>  arch/x86/kernel/setup.c |    5 ++
>>  include/linux/printk.h  |    4 ++
>>  init/main.c             |    1
>>  kernel/printk.c         |   81 +++++++++++++++++++++++++++++-------------------
>>  4 files changed, 60 insertions(+), 31 deletions(-)
>>
>> --- linux.orig/arch/x86/kernel/setup.c
>> +++ linux/arch/x86/kernel/setup.c
>> @@ -1007,6 +1007,11 @@ void __init setup_arch(char **cmdline_p)
>>        memblock_find_dma_reserve();
>>        dma32_reserve_bootmem();
>>
>> +       /*
>> +        * Allocate bigger log buffer as early as possible
>> +        */
>> +       setup_log_buf();
>> +
>>  #ifdef CONFIG_KVM_CLOCK
>>        kvmclock_init();
>>  #endif
>> --- linux.orig/include/linux/printk.h
>> +++ linux/include/linux/printk.h
>> @@ -1,6 +1,8 @@
>>  #ifndef __KERNEL_PRINTK__
>>  #define __KERNEL_PRINTK__
>>
>> +#include <linux/init.h>
>> +
>>  extern const char linux_banner[];
>>  extern const char linux_proc_banner[];
>>
>> @@ -89,6 +91,8 @@ int no_printk(const char *fmt, ...)
>>  extern asmlinkage __attribute__ ((format (printf, 1, 2)))
>>  void early_printk(const char *fmt, ...);
>>
>> +void __init setup_log_buf(void);
>> +
>>  extern int printk_needs_cpu(int cpu);
>>  extern void printk_tick(void);
>>
>> --- linux.orig/init/main.c
>> +++ linux/init/main.c
>> @@ -592,6 +592,7 @@ asmlinkage void __init start_kernel(void
>>         * These use large bootmem allocations and must precede
>>         * kmem_cache_init()
>>         */
>> +       setup_log_buf();
>>        pidhash_init();
>>        vfs_caches_init_early();
>>        sort_main_extable();
>> --- linux.orig/kernel/printk.c
>> +++ linux/kernel/printk.c
>> @@ -162,46 +162,65 @@ void log_buf_kexec_setup(void)
>>  }
>>  #endif
>>
>> +static unsigned long __initdata new_log_buf_len;
>>  static int __init log_buf_len_setup(char *str)
>>  {
>>        unsigned size = memparse(str, &str);
>> -       unsigned long flags;
>>
>>        if (size)
>>                size = roundup_pow_of_two(size);
>> -       if (size > log_buf_len) {
>> -               unsigned start, dest_idx, offset;
>> -               char *new_log_buf;
>> -
>> -               new_log_buf = alloc_bootmem(size);
>> -               if (!new_log_buf) {
>> -                       printk(KERN_WARNING "log_buf_len: allocation failed\n");
>> -                       goto out;
>> -               }
>> -
>> -               spin_lock_irqsave(&logbuf_lock, flags);
>> -               log_buf_len = size;
>> -               log_buf = new_log_buf;
>> -
>> -               offset = start = min(con_start, log_start);
>> -               dest_idx = 0;
>> -               while (start != log_end) {
>> -                       log_buf[dest_idx] = __log_buf[start & (__LOG_BUF_LEN - 1)];
>> -                       start++;
>> -                       dest_idx++;
>> -               }
>> -               log_start -= offset;
>> -               con_start -= offset;
>> -               log_end -= offset;
>> -               spin_unlock_irqrestore(&logbuf_lock, flags);
>> +       if (size > log_buf_len)
>> +               new_log_buf_len = size;
>>
>> -               printk(KERN_NOTICE "log_buf_len: %d\n", log_buf_len);
>> -       }
>> -out:
>> -       return 1;
>> +       return 0;
>>  }
>> +early_param("log_buf_len", log_buf_len_setup);
>>
>> -__setup("log_buf_len=", log_buf_len_setup);
>> +void __init setup_log_buf(void)
>> +{
>> +       unsigned long flags;
>> +       unsigned start, dest_idx, offset;
>> +       char *new_log_buf;
>> +       char first_line[64], *first_nl;
>> +
>> +       if (!new_log_buf_len)
>> +               return;
>> +
>> +       new_log_buf = alloc_bootmem(new_log_buf_len);
>> +       memset(first_line, 0, sizeof(first_line));
> 
> use x86_memblock_find_range in x86 code?
> 
> you can do that much earlier before SRAT etc is parsed.
> 
> Thanks
> 
> Yinghai

I could investigate that, but I didn't want to be too
arch-specific.  Also, we need to backport this to 2.6.32
for the kernel we support on UV (I ported the changes
forward to 2.6.38).

I thought this would be a very clean interface without
any permanent overhead (all in __init sections), and
easily supported on all arches.

Thanks,
Mike

Re: [PATCH 1/5] ACPI: Minimize X2APIC initial messages

[Ingo Molnar]

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

> Minimize X2APIC messages by printing 8 per line and dropping
> the "enabled" flag since that's assumed.  It will still print
> "disabled" if necessary.
> 
> v2: updated to apply to x86-tip
> 
> Signed-off-by: Mike Travis <travis@sgi.com>
> Reviewed-by: Jack Steiner <steiner@sgi.com>
> Reviewed-by: Robin Holt <holt@sgi.com>

If Len acks this then i can queue it up with the other patches. Or if Len wants to 
apply it to the ACPI tree directly that's fine as well.

Len, which is your preference?

Thanks,

	Ingo

Re: [PATCH 2/5] x86: Minimize initial e820 messages

[Ingo Molnar]

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

> --- linux.orig/arch/x86/kernel/e820.c
> +++ linux/arch/x86/kernel/e820.c
> @@ -38,6 +38,8 @@
>   */
>  struct e820map e820;
>  struct e820map e820_saved;
> +struct e820map e820_prev __initdata;
> +int e820_prev_saved __initdata;

Please add comments to the code that describe what these global variables do.

Also, they should be 'static' as they are only used in e820.c, right?

	Ingo

Re: [PATCH 3/5] x86: Minimize SRAT messages

[Ingo Molnar]

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

> Condense the SRAT: messages to show all APIC id's for the
> node on a single line.
> 
> v1: Added pertinent __init & __initdata specifiers.
> v2: updated to apply to x86-tip
> 
> Signed-off-by: Mike Travis <travis@sgi.com>
> Reviewed-by: Jack Steiner <steiner@sgi.com>
> Reviewed-by: Robin Holt <holt@sgi.com>
> ---
>  arch/x86/mm/srat_64.c |   16 ++++++++++++----
>  drivers/acpi/numa.c   |    3 +++
>  2 files changed, 15 insertions(+), 4 deletions(-)
> 
> --- linux.orig/arch/x86/mm/srat_64.c
> +++ linux/arch/x86/mm/srat_64.c
> @@ -116,6 +116,7 @@ acpi_numa_x2apic_affinity_init(struct ac
>  {
>  	int pxm, node;
>  	int apic_id;
> +	static int __initdata last_node = -1, last_pxm = -1;

Please do not put global variables amongst local variables - put them into file 
scope.

> +	} else if (pxm != last_pxm) {
> +		pr_cont(" %u:%u", pxm, apic_id);
> +		last_pxm = pxm;
> +	} else
> +		pr_cont(" :%u", apic_id);

Curly braces should be balanced.

	Ingo

Re: [PATCH 4/5] printk: Minimize time zero output

[Ingo Molnar]

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

> Reduce the length for time zero messages by only printing "[0] ".
> 
> v2: updated to apply to x86-tip
> 
> Signed-off-by: Mike Travis <travis@sgi.com>
> Reviewed-by: Jack Steiner <steiner@sgi.com>
> Reviewed-by: Robin Holt <holt@sgi.com>
> ---
>  kernel/printk.c |    8 +++++---
>  1 file changed, 5 insertions(+), 3 deletions(-)
> 
> --- linux.orig/kernel/printk.c
> +++ linux/kernel/printk.c
> @@ -818,11 +818,13 @@ asmlinkage int vprintk(const char *fmt,
>  				unsigned long nanosec_rem;
>  
>  				t = cpu_clock(printk_cpu);
> -				nanosec_rem = do_div(t, 1000000000);
> -				tlen = sprintf(tbuf, "[%5lu.%06lu] ",
> +				if (likely(t)) {
> +					nanosec_rem = do_div(t, 1000000000);
> +					tlen = sprintf(tbuf, "[%5lu.%06lu] ",
>  						(unsigned long) t,
>  						nanosec_rem / 1000);

The excessive number of very ugly linebreaks in this statement should have told you 
that the whole printk_time function wants to be broken out of vsprintk(), into a 
helper function.

Please make it two patches: one cleanup-only patch that factors out the code, the 
second one that modifies it materially.

Thanks,

	Ingo

Re: [PATCH 5/5] printk: Allocate kernel log buffer earlier

[Ingo Molnar]

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

> +++ linux/kernel/printk.c
> @@ -162,46 +162,65 @@ void log_buf_kexec_setup(void)
>  }
>  #endif
>  
> +static unsigned long __initdata new_log_buf_len;
>  static int __init log_buf_len_setup(char *str)
>  {

Can you see the readability problem this new line introduces?

> +	char first_line[64], *first_nl;

The value 64 looks arbitrary. Needs to be symbolized and explained. (That would also 
make the sizeof(first_line) usage more readable later on.)

> +	pr_info("log_buf_len: %d, first line: %s\n",
> +		log_buf_len, first_line);

It's not just arbitrarily sized, but i dont see where it's guaranteed that it's a 
nil delimited string.

> +	pr_debug("bu: %d/%d (%d%%)\n",
> +		dest_idx, __LOG_BUF_LEN - dest_idx,
> +		(dest_idx * 100) / __LOG_BUF_LEN);

What's that?

Patch looks pretty ad-hoc. No comments whatsoever what the intention is either, so 
the reader has to go figure out the code.

Thanks,

	Ingo