[2.6.27-git-a447c093244] BUG: spinlock bad magic on CPU#0, setserial/3527

[2.6.27-git-a447c093244] BUG: spinlock bad magic on CPU#0, setserial/3527

[Rafael J. Wysocki]

Hi,

The Linus' tree from today on Asus L5D:

BUG: spinlock bad magic on CPU#0, setserial/3527
 lock: ffffffff80dae020, .magic: 00000000, .owner: <none>/-1, .owner_cpu: 0
Pid: 3527, comm: setserial Not tainted 2.6.27-git #57
Call Trace:
 [<ffffffff80345aae>] spin_bug+0xde/0xf0
 [<ffffffff80345bd6>] _raw_spin_lock+0x86/0x140
 [<ffffffff804823ca>] _spin_lock_irq+0x3a/0x50
 [<ffffffff803ae89d>] ? serial8250_startup+0x13d/0x610
 [<ffffffff803ae89d>] serial8250_startup+0x13d/0x610
 [<ffffffff803abd9a>] uart_startup+0x6a/0x1a0
 [<ffffffff803acca5>] uart_open+0x115/0x4a0
 [<ffffffff80482286>] ? _spin_unlock+0x26/0x30
 [<ffffffff8038d271>] ? check_tty_count+0x21/0xc0
 [<ffffffff8039067a>] tty_open+0x1ea/0x440
 [<ffffffff802a8490>] chrdev_open+0xa0/0x1c0
 [<ffffffff802a385c>] __dentry_open+0xcc/0x2c0
 [<ffffffff802a83f0>] ? chrdev_open+0x0/0x1c0
 [<ffffffff802a3a94>] nameidata_to_filp+0x44/0x60
 [<ffffffff802b052d>] do_filp_open+0x1fd/0x8f0
 [<ffffffff802add86>] ? getname+0x36/0x210
 [<ffffffff802bda06>] ? alloc_fd+0x106/0x130
 [<ffffffff802a36ae>] do_sys_open+0x5e/0xf0
 [<ffffffff802a376b>] sys_open+0x1b/0x20
 [<ffffffff8020b66b>] system_call_fastpath+0x16/0x1b

Do I have to bisect? :-)

Rafael

Re: [2.6.27-git-a447c093244] BUG: spinlock bad magic on CPU#0, setserial/3527

[Alan Cox]

On Tue, 14 Oct 2008 00:05:39 +0200
"Rafael J. Wysocki" <rjw@sisk.pl> wrote:

> Hi,
> 
> The Linus' tree from today on Asus L5D:
> 
> BUG: spinlock bad magic on CPU#0, setserial/3527
>  lock: ffffffff80dae020, .magic: 00000000, .owner: <none>/-1, .owner_cpu: 0
> Pid: 3527, comm: setserial Not tainted 2.6.27-git #57

Yep looking at that at the moment. Its a fallout from dropping the NR_IRQ
removal changes from the serial tree just before merging I think. Was
done to make life simpler for Ingo's code push but appears to have
slightly backfired.

Alan

Re: [2.6.27-git-a447c093244] BUG: spinlock bad magic on CPU#0, setserial/3527

[Ingo Molnar]

* Alan Cox <alan@lxorguk.ukuu.org.uk> wrote:

> On Tue, 14 Oct 2008 00:05:39 +0200
> "Rafael J. Wysocki" <rjw@sisk.pl> wrote:
> 
> > Hi,
> > 
> > The Linus' tree from today on Asus L5D:
> > 
> > BUG: spinlock bad magic on CPU#0, setserial/3527
> >  lock: ffffffff80dae020, .magic: 00000000, .owner: <none>/-1, .owner_cpu: 0
> > Pid: 3527, comm: setserial Not tainted 2.6.27-git #57
> 
> Yep looking at that at the moment. Its a fallout from dropping the 
> NR_IRQ removal changes from the serial tree just before merging I 
> think. Was done to make life simpler for Ingo's code push but appears 
> to have slightly backfired.

i too have triggered it:

[   31.099528] BUG: spinlock bad magic on CPU#1, agetty/2608
[   31.101013]  lock: ffffffff8182b020, .magic: 00000000, .owner: agetty/2608, .owner_cpu: 1
[   31.101013] Pid: 2608, comm: agetty Not tainted 2.6.27-tip-03409-g064a754-dirty #42476
[   31.101013] Call Trace:
[   31.101013]  [<ffffffff8041ee15>] spin_bug+0xa2/0xaa
[   31.101013]  [<ffffffff8041ee3e>] _raw_spin_unlock+0x21/0x8a
[   31.101013]  [<ffffffff8089aac5>] _spin_unlock_irq+0x2b/0x36
[   31.101013]  [<ffffffff804a9a7b>] serial8250_startup+0x3f2/0x5a3
[   31.101013]  [<ffffffff804a5b00>] uart_startup+0xa0/0x14b
[   31.101013]  [<ffffffff804a6a5a>] uart_open+0x1a8/0x3f7
[   31.101013]  [<ffffffff8089aafb>] ? _spin_unlock+0x2b/0x2f
[   31.101013]  [<ffffffff8047ec6a>] tty_open+0x2db/0x41c
[   31.101013]  [<ffffffff802ac383>] chrdev_open+0x130/0x151
[   31.101013]  [<ffffffff8089aafb>] ? _spin_unlock+0x2b/0x2f
[   31.101013]  [<ffffffff802ac253>] ? chrdev_open+0x0/0x151
[   31.101013]  [<ffffffff802a7e38>] __dentry_open+0x178/0x274
[   31.101013]  [<ffffffff802a7f67>] nameidata_to_filp+0x33/0x44
[   31.101013]  [<ffffffff802b43df>] do_filp_open+0x3be/0x753
[   31.101013]  [<ffffffff802beb11>] ? alloc_fd+0x101/0x110
[   31.101013]  [<ffffffff8027d9c9>] ? trace_hardirqs_off+0x1e/0x20
[   31.101013]  [<ffffffff8089aafb>] ? _spin_unlock+0x2b/0x2f
[   31.101013]  [<ffffffff802beb11>] ? alloc_fd+0x101/0x110
[   31.101013]  [<ffffffff802a7bce>] do_sys_open+0x58/0xdf
[   31.101013]  [<ffffffff802a7c88>] sys_open+0x20/0x22
[   31.101013]  [<ffffffff8020c1cb>] system_call_fastpath+0x16/0x1b
[   31.405014] eth1: no IPv6 routers present
[   32.947611] ACPI: PCI Interrupt Link [APC3] enabled at IRQ 18

can test any patch for you if it's not easy to reproduce there.

	Ingo

[PATCH] serial: fix serial port lock init

[Ingo Molnar]

> [   31.099528] BUG: spinlock bad magic on CPU#1, agetty/2608

the patch below fixes this. There's another incarnation of the bug that 
i bisected today, a spontaneous reboot crash with certain configs:

| b70ac7718579b5cbf3bdd74fd01132d1c91596f4 is first bad commit
| commit b70ac7718579b5cbf3bdd74fd01132d1c91596f4
| Author: David Miller <davem@davemloft.net>
| Date:   Mon Oct 13 10:36:31 2008 +0100
|
|     serial: allow 8250 to be used on sparc

 # bad:  [e7f2f991] Merge phase #5 (misc) of git://git.kernel.org/pub/
 # good: [3fa8749e] Linux 2.6.27
 # good: [4dd9ec49] Merge git://git.kernel.org/pub/scm/linux/kernel/gi
 # good: [5c3c4d9b] Merge git://git.kernel.org/pub/scm/linux/kernel/gi
 # good: [1a2217a9] Merge git://git.kernel.org/pub/scm/linux/kernel/gi
 # good: [cf81978d] i386: convert hardware exception 15 to an interrup
 # good: [c00193f9] Merge branches 'oprofile-v2' and 'timers/hpet' int
 # bad:  [8f520021] tty: Termios locking - sort out real_tty confusion
 # good: [f1ddfd95] ip2: init/deinit cleanup
 # bad:  [b70ac771] serial: allow 8250 to be used on sparc
 # good: [9bde10a4] serial-make-uart_ports-ioport-unsigned-long-fix
 # good: [43b11d33] ftdi: A few errors are err() that should be debug 
 # good: [b5d674ab] 8250: remove a few inlines of dubious value

( but it's the same basic problem: we lost the lock init sequence when a
  patch was removed from the middle. )

	Ingo

----------------->
>From b15be1e63d0df3a1b4a25e7a28cfca9f93690884 Mon Sep 17 00:00:00 2001
From: Ingo Molnar <mingo@elte.hu>
Date: Tue, 14 Oct 2008 12:14:17 +0200
Subject: [PATCH] serial: fix serial port lock init

Signed-off-by: Ingo Molnar <mingo@elte.hu>
---
 drivers/serial/8250.c |    3 +++
 1 files changed, 3 insertions(+), 0 deletions(-)

diff --git a/drivers/serial/8250.c b/drivers/serial/8250.c
index d4104a3..d3ca7d3 100644
--- a/drivers/serial/8250.c
+++ b/drivers/serial/8250.c
@@ -2969,6 +2969,9 @@ static int __init serial8250_init(void)
 		"%d ports, IRQ sharing %sabled\n", nr_uarts,
 		share_irqs ? "en" : "dis");
 
+	for (i = 0; i < NR_IRQS; i++)
+		spin_lock_init(&irq_lists[i].lock);
+
 #ifdef CONFIG_SPARC
 	ret = sunserial_register_minors(&serial8250_reg, UART_NR);
 #else

Re: [PATCH] serial: fix serial port lock init

[Kamalesh Babulal]

* Ingo Molnar <mingo@elte.hu> [2008-10-14 12:22:53]:

> 
> > [   31.099528] BUG: spinlock bad magic on CPU#1, agetty/2608
> 
> the patch below fixes this. There's another incarnation of the bug that 
> i bisected today, a spontaneous reboot crash with certain configs:
> 
> | b70ac7718579b5cbf3bdd74fd01132d1c91596f4 is first bad commit
> | commit b70ac7718579b5cbf3bdd74fd01132d1c91596f4
> | Author: David Miller <davem@davemloft.net>
> | Date:   Mon Oct 13 10:36:31 2008 +0100
> |
> |     serial: allow 8250 to be used on sparc
> 
>  # bad:  [e7f2f991] Merge phase #5 (misc) of git://git.kernel.org/pub/
>  # good: [3fa8749e] Linux 2.6.27
>  # good: [4dd9ec49] Merge git://git.kernel.org/pub/scm/linux/kernel/gi
>  # good: [5c3c4d9b] Merge git://git.kernel.org/pub/scm/linux/kernel/gi
>  # good: [1a2217a9] Merge git://git.kernel.org/pub/scm/linux/kernel/gi
>  # good: [cf81978d] i386: convert hardware exception 15 to an interrup
>  # good: [c00193f9] Merge branches 'oprofile-v2' and 'timers/hpet' int
>  # bad:  [8f520021] tty: Termios locking - sort out real_tty confusion
>  # good: [f1ddfd95] ip2: init/deinit cleanup
>  # bad:  [b70ac771] serial: allow 8250 to be used on sparc
>  # good: [9bde10a4] serial-make-uart_ports-ioport-unsigned-long-fix
>  # good: [43b11d33] ftdi: A few errors are err() that should be debug 
>  # good: [b5d674ab] 8250: remove a few inlines of dubious value
> 
> ( but it's the same basic problem: we lost the lock init sequence when a
>   patch was removed from the middle. )
> 
> 	Ingo
> 
> ----------------->
> From b15be1e63d0df3a1b4a25e7a28cfca9f93690884 Mon Sep 17 00:00:00 2001
> From: Ingo Molnar <mingo@elte.hu>
> Date: Tue, 14 Oct 2008 12:14:17 +0200
> Subject: [PATCH] serial: fix serial port lock init
> 

Thanks, the patch fixes the warning.

Tested-by: Kamalesh Babulal <kamalesh@linux.vnet.ibm.com>

> Signed-off-by: Ingo Molnar <mingo@elte.hu>
> ---
>  drivers/serial/8250.c |    3 +++
>  1 files changed, 3 insertions(+), 0 deletions(-)
> 
> diff --git a/drivers/serial/8250.c b/drivers/serial/8250.c
> index d4104a3..d3ca7d3 100644
> --- a/drivers/serial/8250.c
> +++ b/drivers/serial/8250.c
> @@ -2969,6 +2969,9 @@ static int __init serial8250_init(void)
>  		"%d ports, IRQ sharing %sabled\n", nr_uarts,
>  		share_irqs ? "en" : "dis");
> 
> +	for (i = 0; i < NR_IRQS; i++)
> +		spin_lock_init(&irq_lists[i].lock);
> +
>  #ifdef CONFIG_SPARC
>  	ret = sunserial_register_minors(&serial8250_reg, UART_NR);
>  #else
> 
-- 
Thanks & Regards,
Kamalesh Babulal,
Linux Technology Center,
IBM, ISTL.