http://lkml.org/lkml/2009/9/23/305

>       early_printk: Allow more than one early console

this patch broke things pretty badly on x86, with pretty much any 
config, as long as the early console is used - which most of my 
test-systems do :-(

I'm getting an early boot hard lockup, which is due to an infinite 
stream of:

[    0.000000] BIOS-provided physical RAM map:
[    0.000000]  BIOS-e820: 0000000000000000 - 000000000009f800 (usable)
[    0.000000]  BIOS-e820: 000000000009f800 - 00000000000a0000 (reserved)
[    0.000000]  BIOS-e820: 00000000000f0000 - 0000000000100000 (reserved)
[    0.000000]  BIOS-e820: 0000000000100000 - 000000003fff0000 (usable)
[    0.000000]  BIOS-e820: 000000003fff0000 - 000000003fff3000 (ACPI NVS)
[    0.000000]  BIOS-e820: 000000003fff3000 - 0000000040000000 (ACPI data)
[    0.000000]  BIOS-e820: 00000000e0000000 - 00000000f0000000 (reserved)
[    0.000000]  BIOS-e820: 00000000fec00000 - 0000000100000000 (reserved)
[    0.000000] console [earlyser0] enabled
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpuset
[ ... ]
i've reverted it via the patch below, as it clearly has unintended side 
effects.

	Ingo

>From 1070163596c13d3c34809c747c7800b3b06b158e Mon Sep 17 00:00:00 2001
From: Ingo Molnar <[email protected]>
Date: Wed, 23 Sep 2009 19:31:04 +0200
Subject: [PATCH] Revert "early_printk: Allow more than one early console"

This reverts commit c9530948bc626c8b638015c0b32abb9615659ec6.
---
 arch/x86/kernel/early_printk.c |   65 +++++++++++++++++++--------------------
 1 files changed, 32 insertions(+), 33 deletions(-)
diff --git a/arch/x86/kernel/early_printk.c b/arch/x86/kernel/early_printk.c
index 2acfd3f..519a5e1 100644
--- a/arch/x86/kernel/early_printk.c
+++ b/arch/x86/kernel/early_printk.c
@@ -176,19 +176,10 @@ asmlinkage void early_printk(const char *fmt, ...)
 	va_end(ap);
 }
 
-static inline void early_console_register(struct console *con, int keep_early)
-{
-	early_console = con;
-	if (keep_early)
-		early_console->flags &= ~CON_BOOT;
-	else
-		early_console->flags |= CON_BOOT;
-	register_console(early_console);
-}
 
 static int __init setup_early_printk(char *buf)
 {
-	int keep;
+	int keep_early;
 
 	if (!buf)
 		return 0;
@@ -197,34 +188,42 @@ static int __init setup_early_printk(char *buf)
 		return 0;
 	early_console_initialized = 1;
 
-	keep = (strstr(buf, "keep") != NULL);
-
-	while (*buf != '\0') {
-		if (!strncmp(buf, "serial", 6)) {
-			early_serial_init(buf + 6);
-			early_console_register(&early_serial_console, keep);
-		}
-		if (!strncmp(buf, "ttyS", 4)) {
-			early_serial_init(buf + 4);
-			early_console_register(&early_serial_console, keep);
-		}
-		if (!strncmp(buf, "vga", 3) &&
-		    boot_params.screen_info.orig_video_isVGA == 1) {
-			max_xpos = boot_params.screen_info.orig_video_cols;
-			max_ypos = boot_params.screen_info.orig_video_lines;
-			current_ypos = boot_params.screen_info.orig_y;
-			early_console_register(&early_vga_console, keep);
-		}
+	keep_early = (strstr(buf, "keep") != NULL);
+
+	if (!strncmp(buf, "serial", 6)) {
+		early_serial_init(buf + 6);
+		early_console = &early_serial_console;
+	} else if (!strncmp(buf, "ttyS", 4)) {
+		early_serial_init(buf);
+		early_console = &early_serial_console;
+	} else if (!strncmp(buf, "vga", 3)
+		&& boot_params.screen_info.orig_video_isVGA == 1) {
+		max_xpos = boot_params.screen_info.orig_video_cols;
+		max_ypos = boot_params.screen_info.orig_video_lines;
+		current_ypos = boot_params.screen_info.orig_y;
+		early_console = &early_vga_console;
 #ifdef CONFIG_EARLY_PRINTK_DBGP
-		if (!strncmp(buf, "dbgp", 4) && !early_dbgp_init(buf + 4))
-			early_console_register(&early_dbgp_console, keep);
+	} else if (!strncmp(buf, "dbgp", 4)) {
+		if (early_dbgp_init(buf+4) < 0)
+			return 0;
+		early_console = &early_dbgp_console;
+		/*
+		 * usb subsys will reset ehci controller, so don't keep
+		 * that early console
+		 */
+		keep_early = 0;
 #endif
 #ifdef CONFIG_HVC_XEN
-		if (!strncmp(buf, "xen", 3))
-			early_console_register(&xenboot_console, keep);
+	} else if (!strncmp(buf, "xen", 3)) {
+		early_console = &xenboot_console;
 #endif
-		buf++;
 	}
+
+	if (keep_early)
+		early_console->flags &= ~CON_BOOT;
+	else
+		early_console->flags |= CON_BOOT;
+	register_console(early_console);
 	return 0;
 }
 

* Jason Wessel <[email protected]> wrote:
> Ingo Molnar wrote:
> >>       early_printk: Allow more than one early console
> >> 
> >
> > this patch broke things pretty badly on x86, with pretty much any 
> > config, as long as the early console is used - which most of my 
> > test-systems do :-(
> > 
> 
> Ingo,
> 
> Can you send me the boot args and kernel config you are using?  I'd 
> like to figure out which part was at fault and fix it up.

will do. Will take some time though - trying to track down a new boot 
crash as well:

acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
initcall acpiphp_init+0x0/0x83 returned -19 after 16410 usecs
calling  ibm_acpiphp_init+0x0/0x190 @ 1
BUG: unable to handle kernel NULL pointer dereference at 0000000000000003
IP: [<ffffffff82b07130>] ibm_find_acpi_device+0x5c/0xf5
PGD 0 
Oops: 0002 [#1] SMP DEBUG_PAGEALLOC
last sysfs file: 
CPU 0 
Pid: 1, comm: swapper Not tainted 2.6.31-tip #16786 System Product Name
RIP: 0010:[<ffffffff82b07130>]  [<ffffffff82b07130>] ibm_find_acpi_device+0x5c/0xf5
RSP: 0018:ffff88003f2d1d60  EFLAGS: 00010246
RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
RDX: ffff88003f2d1d68 RSI: 00000000000001e4 RDI: 0000000000000000
RBP: ffff88003f2d1d90 R08: 0000000000000001 R09: ffffffff824b645b
R10: 000000002d0ef63b R11: ffff88003f2d1a80 R12: ffff88003fa780d0
R13: ffffffff83940dc8 R14: 0000000000000001 R15: ffffffff83942e10
FS:  0000000000000000(0000) GS:ffff880005800000(0000) knlGS:0000000000000000
CS:  0010 DS: 0018 ES: 0018 CR0: 000000008005003b
CR2: 0000000000000003 CR3: 0000000001001000 CR4: 00000000000006b0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Process swapper (pid: 1, threadinfo ffff88003f2d0000, task ffff88003f2c8000)
Stack:
 ffff88003f2c8000 ffff88003cfbb690 000000002d0ef63b 0000000000000000
<0> 0000000000000000 ffff88003fa780d0 ffff88003f2d1e10 ffffffff8156b6b6
<0> 0000000000000001 0000000100000000 0000000000000000 ffffffff83940dc8
Call Trace:
 [<ffffffff8156b6b6>] acpi_ns_walk_namespace+0x11d/0x234
 [<ffffffff82b070d4>] ? ibm_find_acpi_device+0x0/0xf5
 [<ffffffff8157b159>] ? acpi_ut_acquire_mutex+0xd9/0x12e
 [<ffffffff82b070d4>] ? ibm_find_acpi_device+0x0/0xf5
 [<ffffffff81566dfa>] acpi_walk_namespace+0x105/0x162
 [<ffffffff81d067bf>] ? acpi_pm_read+0xd/0x3e
 [<ffffffff82b06f44>] ? ibm_acpiphp_init+0x0/0x190
 [<ffffffff82b06fa8>] ibm_acpiphp_init+0x64/0x190
 [<ffffffff810090b4>] do_one_initcall+0x82/0x1a6
 [<ffffffff810edecc>] ? init_irq_proc+0x77/0x9a
 [<ffffffff82ad8975>] do_basic_setup+0x5e/0x87
 [<ffffffff82ad8a26>] kernel_init+0x88/0xe2
 [<ffffffff8103ddfa>] child_rip+0xa/0x20
 [<ffffffff8103d7bc>] ? restore_args+0x0/0x30
 [<ffffffff82ad899e>] ? kernel_init+0x0/0xe2
 [<ffffffff8103ddf0>] ? child_rip+0x0/0x20
Code: 48 c7 c2 c0 7b 0b 82 48 c7 c6 95 39 4a 82 48 c7 c7 1a 3c 4a 82 31 c0 e8 02 84 4b ff 31 c0 e9 82 00 00 00 48 8b 45 d8 48 8b 40 30 <c6> 40 03 00 48 8b 45 d8 83 78 18 00 74 5f f6 40 0d 04 74 59 48 
RIP  [<ffffffff82b07130>] ibm_find_acpi_device+0x5c/0xf5
 RSP <ffff88003f2d1d60>
CR2: 0000000000000003
---[ end trace 5a5d197966b56a2e ]---
Kernel panic - not syncing: Fatal exception
Pid: 1, comm: swapper Tainted: G      D    2.6.31-tip #16786
/me looks in the general direction of Len ;-)



* Ingo Molnar <[email protected]> wrote:


> The commit point to which the attached config and bootlog belongs is:
> 
>   2.6.31-07863-gb64ada6
> 
> Reverting:
> 
>   c953094: early_printk: Allow more than one early console
> 
> solves it.

btw., the boot options are:

Command line: root=/dev/sda6 earlyprintk=serial,ttyS0,115200 console=ttyS0,115200 debug
initcall_debug apic=verbose sysrq_always_enabled ignore_loglevel 
selinux=0 nmi_watchdog=0 panic=1 3

So it's nothing out of the ordinary - typical early-printk use: handover 
from earlyprintk serial console to the real serial console.

	Ingo



Ingo Molnar wrote:
> * Ingo Molnar <[email protected]> wrote:
>
>
> 
>> The commit point to which the attached config and bootlog belongs is:
>>
>>   2.6.31-07863-gb64ada6
>>
>> Reverting:
>>
>>   c953094: early_printk: Allow more than one early console
>>
>> solves it.
>> 
>
> btw., the boot options are:
>
> Command line: root=/dev/sda6 earlyprintk=serial,ttyS0,115200 console=ttyS0,115200 debug
> initcall_debug apic=verbose sysrq_always_enabled ignore_loglevel 
> selinux=0 nmi_watchdog=0 panic=1 3
>
> 

AH HA!

earlyprintk=serial,ttyS0,115200

You are invoking the same device twice which is why you are having infinite recursion.  It was not obvious to me why the earlyprintk code would allow "serial" or "ttyS", but perhaps we need to protect for that?

Your boot line should be:

earlyprintk=serial,115200

OR

earlyprintk=ttyS0,115200

The line you had there before would have been the equivalent of doing:

earlyprintk=ttyS0,ttyS0,115200

Given this, do we still need to execute the revert your revert?  Or perhaps do we need to add some protection?

Thanks,
Jason.




On Wed, 23 Sep 2009, Jason Wessel wrote:
> 
> Perhaps you will consider adding this patch to your tree?   It fixes the
> specific case you mentioned.  It will still allow the board to boot and
> instead of crashing, print a warning on the second instance.

Ugh. This looks totally bogus.

Why don't you just add CON_REGISTERED to the console flags, and do

	/* Already registered? */
	if (early_console->flags & CON_REGISTERED)
		return;
	early_console->flags |= CON_REGISTERED;
there instead? That whole "loop over existing consoles to check their 
names" looks silly and broken, and you're already playing with the flags 
in there (CON_BOOT).

		Linus



Linus Torvalds wrote:
> On Wed, 23 Sep 2009, Jason Wessel wrote:
> 
>> Perhaps you will consider adding this patch to your tree?   It fixes the
>> specific case you mentioned.  It will still allow the board to boot and
>> instead of crashing, print a warning on the second instance.
>> 
>
> Ugh. This looks totally bogus.
>
> Why don't you just add CON_REGISTERED to the console flags, and do
>
> 	/* Already registered? */
> 	if (early_console->flags & CON_REGISTERED)
> 		return;
> 	early_console->flags |= CON_REGISTERED;
>
> there instead? That whole "loop over existing consoles to check their 
> names" looks silly and broken, and you're already playing with the flags 
> in there (CON_BOOT).
> 

Seems reasonable to me.  We don't even have to add a new flag, because
we already have the index set to != -1 when the console registration
succeeds.

Here is the revised patch.

Jason.


>From 66081d4a28cb17f58b09fe05a5a9c8441fc701ac Mon Sep 17 00:00:00 2001
From: Jason Wessel <[email protected]>
Date: Wed, 23 Sep 2009 18:11:31 -0500
Subject: [PATCH 1/1] early_printk: Protect against using the same device twice

If you use the kernel argument:

earlyprintk=serial,ttyS0,115200

This will cause a recursive crash.  Instead warn the end user that they
specified the device a second time.

Signed-off-by: Jason Wessel <[email protected]>
---
 arch/x86/kernel/early_printk.c |    5 +++++
 1 files changed, 5 insertions(+), 0 deletions(-)
diff --git a/arch/x86/kernel/early_printk.c b/arch/x86/kernel/early_printk.c
index 2acfd3f..41fd965 100644
--- a/arch/x86/kernel/early_printk.c
+++ b/arch/x86/kernel/early_printk.c
@@ -178,6 +178,11 @@ asmlinkage void early_printk(const char *fmt, ...)
 
 static inline void early_console_register(struct console *con, int keep_early)
 {
+	if (early_console->index != -1) {
+		printk(KERN_CRIT "ERROR: earlyprintk= %s already used\n",
+		       con->name);
+		return;
+	}
 	early_console = con;
 	if (keep_early)
 		early_console->flags &= ~CON_BOOT;
-- 
1.6.3.1.9.g95405b

Reply via email to