* Mutex debug lock failure [was Re: Bad gcc-4.1.0 leads to Power4 crashes... and power5 too, actually
[not found] ` <1166650134.6673.9.camel@localhost.localdomain>
@ 2006-12-20 23:03 ` Linas Vepstas
2006-12-20 23:09 ` Benjamin Herrenschmidt
0 siblings, 1 reply; 7+ messages in thread
From: Linas Vepstas @ 2006-12-20 23:03 UTC (permalink / raw)
To: Benjamin Herrenschmidt, Ingo Molnar
Cc: Peter Bergner, linuxppc-dev, linux-kernel
On Thu, Dec 21, 2006 at 08:28:54AM +1100, Benjamin Herrenschmidt wrote:
> On Wed, 2006-12-20 at 15:19 -0600, Linas Vepstas wrote:
> > On Tue, Dec 19, 2006 at 07:46:50PM -0600, Peter Bergner wrote:
> >
> > I'm trying to figure out how to try a different compiler,
> > I'm hoping that 3.3 can still compile new kernels.
> >
> > I'll try to stare at the dump a bit too, now.
>
> I've been using 4.1.2 from debian/ubuntu happily lately.
Do you have mutex debugging turned on?
It doesn't seem to be a compiler bug. Fails in the same place,
when compiled with gcc-3.3
Reading the code, it looks like the test case double_unlock_mutex()
fails, because the mutex lock->owner == NULL.
whereas, in kernel/mutex-debug.c, it wanted
void debug_mutex_unlock(struct mutex *lock) {
DEBUG_LOCKS_WARN_ON(lock->owner != current_thread_info());
This is called from
lib/locking-selftest.c circa line 490
#include "locking-selftest-mutex.h"
GENERATE_TESTCASE(double_unlock_mutex)
This may be because include/linux/mutex-debug.h which has
__DEBUG_MUTEX_INITIALIZER in it, failes to set .owner to
any interesting value.
WHile I desperately want to conclude that the mutex lock debug
code is broken, it seems to be unchanged fron 2.6.19
(and seems to work fine in 2.6.19-git7), so I am confused.
This also doesn't explain the bizarre form of the failure on
power4 ... does power4 mishandle twi somehow? Will investigate
next.
--linas
p.s. To recap: above report is for linux-2.6.20-rc1-git6
I get the following on power5:
97742.318323] A-B-B-C-C-D-D-A deadlock:failed|failed| ok |failed|failed|failed|
[97742.318352] A-B-C-D-B-D-D-A deadlock:failed|failed| ok |failed|failed|failed|
[97742.318380] A-B-C-D-B-C-D-A deadlock:failed|failed| ok |failed|failed|failed|
[97742.318408] double unlock: ok | ok |failed|<0>------------[ cut here ]------------
[97742.318440] Kernel BUG at c00000000007d574 [verbose debug info
unavailable]
cpu 0x0: Vector: 700 (Program Check) at [c0000000007a3980]
pc: c00000000007d574: .debug_mutex_unlock+0x5c/0x118
lr: c000000000468068: .__mutex_unlock_slowpath+0x104/0x198
sp: c0000000007a3c00
msr: 8000000000029032
current = 0xc000000000663690
paca = 0xc000000000663f80
pid = 0, comm = swapper
enter ? for help
[c0000000007a3c80] c000000000468068 .__mutex_unlock_slowpath+0x104/0x198
[c0000000007a3d20] c000000000231da8 .double_unlock_mutex+0x3c/0x58
[c0000000007a3db0] c00000000023b47c .dotest+0x5c/0x370
[c0000000007a3e50] c00000000023bc0c .locking_selftest+0x47c/0x17fc
[c0000000007a3ef0] c0000000005f06ec .start_kernel+0x1e4/0x344
[c0000000007a3f90] c0000000000084c8 .start_here_common+0x54/0x8c
0:mon>
0:mon> r
0:mon> di c00000000007d518
c00000000007d518 7c0802a6 mflr r0
c00000000007d51c fbc1fff0 std r30,-16(r1)
c00000000007d520 fbe1fff8 std r31,-8(r1)
c00000000007d524 ebc2d708 ld r30,-10488(r2)
c00000000007d528 7c7f1b78 mr r31,r3
c00000000007d52c f8010010 std r0,16(r1)
c00000000007d530 f821ff81 stdu r1,-128(r1)
c00000000007d534 e93e8008 ld r9,-32760(r30)
r9 = toc ptr debug_locks
c00000000007d538 80090000 lwz r0,0(r9)
c00000000007d53c 2f800000 cmpwi cr7,r0,0
c00000000007d540 419e00d8 beq cr7,c00000000007d618 # .debug_mutex_unlock+0x100/0x118
if (unlikely(!debug_locks)) return;
c00000000007d544 e8030030 ld r0,48(r3)
r0 = lock-> owner == NULL
c00000000007d548 78290464 rldicr r9,r1,0,49
r9 = bottom 14 bits lopped off of stack pointer, giving current ptr
c00000000007d54c 7fa04800 cmpd cr7,r0,r9
c00000000007d550 41be0028 beq cr7,c00000000007d578 # .debug_mutex_unlock+0x60/0x118
c00000000007d554 e93e8000 ld r9,-32768(r30)
c00000000007d558 80090000 lwz r0,0(r9)
c00000000007d55c 2f800000 cmpwi cr7,r0,0
c00000000007d560 409e0014 bne cr7,c00000000007d574 # .debug_mutex_unlock+0x5c/0x118
c00000000007d564 481b1f4d bl c00000000022f4b0 # .debug_locks_off+0x0/0x64
c00000000007d568 60000000 nop
c00000000007d56c 2fa30000 cmpdi cr7,r3,0
c00000000007d570 419e0008 beq cr7,c00000000007d578 # .debug_mutex_unlock+0x60/0x118
c00000000007d574 0fe00000 twi 31,r0,0
crash here
void debug_mutex_unlock(struct mutex *lock)
{
if (unlikely(!debug_locks))
return;
DEBUG_LOCKS_WARN_ON(lock->owner != current_thread_info());
DEBUG_LOCKS_WARN_ON(lock->magic != lock);
DEBUG_LOCKS_WARN_ON(!lock->wait_list.prev && !lock->wait_list.next);
DEBUG_LOCKS_WARN_ON(lock->owner != current_thread_info());
}
r3 is struct mutex, which is
0:mon> d c0000000006c12c0
c0000000006c12c0 0000000100000000 80000000dead4ead |..............N.|
c0000000006c12d0 ffffffff00000000 ffffffffffffffff |................|
c0000000006c12e0 c0000000006c12e0 c0000000006c12e0 |.....l.......l..|
c0000000006c12f0 0000000000000000 0000000000000000 |................|
c0000000006c1300 c0000000006c12c0 0000000000000000 |.....l..........|
c0000000006c1310 00000000dead4ead ffffffff00000000 |......N.........|
c0000000006c1320 ffffffffffffffff c0000000006c1328 |.............l.(|
c0000000006c1330 c0000000006c1328 0000000100000000 |.....l.(........|
struct mutex {
/* 1: unlocked, 0: locked, negative: locked, possible waiters */
atomic_t count; // 1
spinlock_t wait_lock; // 80000000dead4ead ffffffff00000000 ffffffffffffffff
struct list_head wait_list; // c0000000006c12e0 c0000000006c12e0
#ifdef CONFIG_DEBUG_MUTEXES
struct thread_info *owner; // 0000000000000000
const char *name; // 0000000000000000
void *magic; // c0000000006c12c0
#endif
#ifdef CONFIG_DEBUG_LOCK_ALLOC
struct lockdep_map dep_map;
#endif
};
typedef struct {
raw_spinlock_t raw_lock; // 80000000
#if defined(CONFIG_PREEMPT) && defined(CONFIG_SMP) // # CONFIG_PREEMPT
is not set
unsigned int break_lock;
#endif
#ifdef CONFIG_DEBUG_SPINLOCK
unsigned int magic, owner_cpu; // dead4ead ffffffff
void *owner; // ffffffffffffffff
#endif
#ifdef CONFIG_DEBUG_LOCK_ALLOC
struct lockdep_map dep_map;
#endif
} spinlock_t;
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: Mutex debug lock failure [was Re: Bad gcc-4.1.0 leads to Power4 crashes... and power5 too, actually
2006-12-20 23:03 ` Mutex debug lock failure [was Re: Bad gcc-4.1.0 leads to Power4 crashes... and power5 too, actually Linas Vepstas
@ 2006-12-20 23:09 ` Benjamin Herrenschmidt
2006-12-20 23:46 ` Linas Vepstas
0 siblings, 1 reply; 7+ messages in thread
From: Benjamin Herrenschmidt @ 2006-12-20 23:09 UTC (permalink / raw)
To: Linas Vepstas; +Cc: Ingo Molnar, Peter Bergner, linuxppc-dev, linux-kernel
> This also doesn't explain the bizarre form of the failure on
> power4 ... does power4 mishandle twi somehow? Will investigate
> next.
Or you hit it before you have a console ?
Ben.
> --linas
>
> p.s. To recap: above report is for linux-2.6.20-rc1-git6
>
> I get the following on power5:
>
> 97742.318323] A-B-B-C-C-D-D-A deadlock:failed|failed| ok |failed|failed|failed|
> [97742.318352] A-B-C-D-B-D-D-A deadlock:failed|failed| ok |failed|failed|failed|
> [97742.318380] A-B-C-D-B-C-D-A deadlock:failed|failed| ok |failed|failed|failed|
> [97742.318408] double unlock: ok | ok |failed|<0>------------[ cut here ]------------
> [97742.318440] Kernel BUG at c00000000007d574 [verbose debug info
> unavailable]
> cpu 0x0: Vector: 700 (Program Check) at [c0000000007a3980]
> pc: c00000000007d574: .debug_mutex_unlock+0x5c/0x118
> lr: c000000000468068: .__mutex_unlock_slowpath+0x104/0x198
> sp: c0000000007a3c00
> msr: 8000000000029032
> current = 0xc000000000663690
> paca = 0xc000000000663f80
> pid = 0, comm = swapper
> enter ? for help
> [c0000000007a3c80] c000000000468068 .__mutex_unlock_slowpath+0x104/0x198
> [c0000000007a3d20] c000000000231da8 .double_unlock_mutex+0x3c/0x58
> [c0000000007a3db0] c00000000023b47c .dotest+0x5c/0x370
> [c0000000007a3e50] c00000000023bc0c .locking_selftest+0x47c/0x17fc
> [c0000000007a3ef0] c0000000005f06ec .start_kernel+0x1e4/0x344
> [c0000000007a3f90] c0000000000084c8 .start_here_common+0x54/0x8c
> 0:mon>
> 0:mon> r
>
> 0:mon> di c00000000007d518
> c00000000007d518 7c0802a6 mflr r0
> c00000000007d51c fbc1fff0 std r30,-16(r1)
> c00000000007d520 fbe1fff8 std r31,-8(r1)
> c00000000007d524 ebc2d708 ld r30,-10488(r2)
> c00000000007d528 7c7f1b78 mr r31,r3
> c00000000007d52c f8010010 std r0,16(r1)
> c00000000007d530 f821ff81 stdu r1,-128(r1)
> c00000000007d534 e93e8008 ld r9,-32760(r30)
> r9 = toc ptr debug_locks
> c00000000007d538 80090000 lwz r0,0(r9)
> c00000000007d53c 2f800000 cmpwi cr7,r0,0
> c00000000007d540 419e00d8 beq cr7,c00000000007d618 # .debug_mutex_unlock+0x100/0x118
> if (unlikely(!debug_locks)) return;
>
> c00000000007d544 e8030030 ld r0,48(r3)
> r0 = lock-> owner == NULL
> c00000000007d548 78290464 rldicr r9,r1,0,49
> r9 = bottom 14 bits lopped off of stack pointer, giving current ptr
>
> c00000000007d54c 7fa04800 cmpd cr7,r0,r9
> c00000000007d550 41be0028 beq cr7,c00000000007d578 # .debug_mutex_unlock+0x60/0x118
> c00000000007d554 e93e8000 ld r9,-32768(r30)
> c00000000007d558 80090000 lwz r0,0(r9)
> c00000000007d55c 2f800000 cmpwi cr7,r0,0
> c00000000007d560 409e0014 bne cr7,c00000000007d574 # .debug_mutex_unlock+0x5c/0x118
> c00000000007d564 481b1f4d bl c00000000022f4b0 # .debug_locks_off+0x0/0x64
> c00000000007d568 60000000 nop
> c00000000007d56c 2fa30000 cmpdi cr7,r3,0
> c00000000007d570 419e0008 beq cr7,c00000000007d578 # .debug_mutex_unlock+0x60/0x118
> c00000000007d574 0fe00000 twi 31,r0,0
>
> crash here
>
> void debug_mutex_unlock(struct mutex *lock)
> {
> if (unlikely(!debug_locks))
> return;
>
> DEBUG_LOCKS_WARN_ON(lock->owner != current_thread_info());
> DEBUG_LOCKS_WARN_ON(lock->magic != lock);
> DEBUG_LOCKS_WARN_ON(!lock->wait_list.prev && !lock->wait_list.next);
> DEBUG_LOCKS_WARN_ON(lock->owner != current_thread_info());
> }
>
> r3 is struct mutex, which is
>
> 0:mon> d c0000000006c12c0
> c0000000006c12c0 0000000100000000 80000000dead4ead |..............N.|
> c0000000006c12d0 ffffffff00000000 ffffffffffffffff |................|
> c0000000006c12e0 c0000000006c12e0 c0000000006c12e0 |.....l.......l..|
> c0000000006c12f0 0000000000000000 0000000000000000 |................|
> c0000000006c1300 c0000000006c12c0 0000000000000000 |.....l..........|
> c0000000006c1310 00000000dead4ead ffffffff00000000 |......N.........|
> c0000000006c1320 ffffffffffffffff c0000000006c1328 |.............l.(|
> c0000000006c1330 c0000000006c1328 0000000100000000 |.....l.(........|
>
> struct mutex {
> /* 1: unlocked, 0: locked, negative: locked, possible waiters */
> atomic_t count; // 1
> spinlock_t wait_lock; // 80000000dead4ead ffffffff00000000 ffffffffffffffff
> struct list_head wait_list; // c0000000006c12e0 c0000000006c12e0
> #ifdef CONFIG_DEBUG_MUTEXES
> struct thread_info *owner; // 0000000000000000
> const char *name; // 0000000000000000
> void *magic; // c0000000006c12c0
> #endif
> #ifdef CONFIG_DEBUG_LOCK_ALLOC
> struct lockdep_map dep_map;
> #endif
> };
>
> typedef struct {
> raw_spinlock_t raw_lock; // 80000000
> #if defined(CONFIG_PREEMPT) && defined(CONFIG_SMP) // # CONFIG_PREEMPT
> is not set
> unsigned int break_lock;
> #endif
> #ifdef CONFIG_DEBUG_SPINLOCK
> unsigned int magic, owner_cpu; // dead4ead ffffffff
> void *owner; // ffffffffffffffff
> #endif
> #ifdef CONFIG_DEBUG_LOCK_ALLOC
> struct lockdep_map dep_map;
> #endif
> } spinlock_t;
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: Mutex debug lock failure [was Re: Bad gcc-4.1.0 leads to Power4 crashes... and power5 too, actually
2006-12-20 23:09 ` Benjamin Herrenschmidt
@ 2006-12-20 23:46 ` Linas Vepstas
2006-12-21 0:36 ` Anton Blanchard
0 siblings, 1 reply; 7+ messages in thread
From: Linas Vepstas @ 2006-12-20 23:46 UTC (permalink / raw)
To: Benjamin Herrenschmidt
Cc: Ingo Molnar, Peter Bergner, linuxppc-dev, linux-kernel
On Thu, Dec 21, 2006 at 10:09:55AM +1100, Benjamin Herrenschmidt wrote:
>
> > This also doesn't explain the bizarre form of the failure on
> > power4 ... does power4 mishandle twi somehow? Will investigate
> > next.
>
> Or you hit it before you have a console ?
Ahh... I was about to claim I have a console, but on closer
examination: someone has been messing with consoles?
I don't get it ... The power4 has ony a serial connection.
the power5 has a graphics card in it, unused.
The power5 has "Console: colour dummy device 80x25"
kick in, at which point the time goes crazy as well.
There may be multiple bugs here.
The weird crash for 2.6.19-git7 on power4 looks like this:
Looking for displays
opening PHB /pci@400000000110... done
opening PHB /pci@400000000111... done
instantiating rtas at 0x000000002fd10000 ... done
0000000000000000 : boot cpu 0000000000000000
copying OF device tree ...
Building dt strings...
Building dt structure...
Device tree strings 0x00000000043a0000 -> 0x00000000043a135c
Device tree struct 0x00000000043b0000 -> 0x00000000043c0000
Calling quiesce ...
returning from prom_init
[ 0.000000] Starting Linux PPC64 #0 SMP Tue Dec 5 17:20:17 CST 2006
[ 0.000000] -----------------------------------------------------
[ 0.000000] ppc64_pft_size = 0x0
[ 0.000000] physicalMemorySize = 0x400000000
[ 0.000000] ppc64_caches.dcache_line_size = 0x80
[ 0.000000] ppc64_caches.icache_line_size = 0x80
[ 0.000000] htab_address = 0xc0000003e0000000
[ 0.000000] htab_hash_mask = 0x1fffff
[ 0.000000] -----------------------------------------------------
[ 0.000000] Linux version 2.6.19-git7linas (root@venn) (gcc version
4.1.0 (SUSE Linux)) #0 SMP Tue Dec 5 17:20:17 CST 2006
[ 0.000000] [boot]0012 Setup Arch
[ 0.000000] No ramdisk, default root is /dev/sda2
[ 0.000000] EEH: PCI Enhanced I/O Error Handling Enabled
[ 0.000000] PPC64 nvram contains 81920 bytes
[ 0.000000] Zone PFN ranges:
[ 0.000000] DMA 0 -> 262144
[ 0.000000] Normal 262144 -> 262144
[ 0.000000] early_node_map[1] active PFN ranges
[ 0.000000] 0: 0 -> 262144
[ 0.000000] [boot]0015 Setup Done
[ 0.000000] Built 1 zonelists. Total pages: 261888
[ 0.000000] Kernel command line: root=/dev/sda3 console=ttyS0
selinux=0 elevator=cfq kdb=on
[ 0.000000] [boot]0020 XICS Init
[ 0.000000] i8259 legacy interrupt controller initialized
[ 0.000000] [boot]0021 XICS Done
[ 0.000000] PID hash table entries: 4096 (order: 12, 32768 bytes)
System assert at: file: rtas_io_config.c -- line: 195
rio_hub_num: 10
drawer_num: 6
phb_num: 3
buid: 7
which should be compared to 2.6.20-rc1-git6, build with the same
.config, on power4:
Looking for displays
opening PHB /pci@400000000110... done
opening PHB /pci@400000000111... done
instantiating rtas at 0x000000002fd10000 ... done
0000000000000000 : boot cpu 0000000000000000
copying OF device tree ...
Building dt strings...
Building dt structure...
Device tree strings 0x0000000004380000 -> 0x000000000438135c
Device tree struct 0x0000000004390000 -> 0x00000000043a0000
Calling quiesce ...
returning from prom_init
[ 0.000000] Starting Linux PPC64 #0 SMP Tue Dec 19 17:42:44 CST 2006
[ 0.000000] -----------------------------------------------------
[ 0.000000] ppc64_pft_size = 0x0
[ 0.000000] physicalMemorySize = 0x400000000
[ 0.000000] ppc64_caches.dcache_line_size = 0x80
[ 0.000000] ppc64_caches.icache_line_size = 0x80
[ 0.000000] htab_address = 0xc0000003e0000000
[ 0.000000] htab_hash_mask = 0x1fffff
[ 0.000000] -----------------------------------------------------
[ 0.000000] Linux version 2.6.20-rc1-git6linas (root@venn) (gcc
version 4.1.0 (SUSE Linux)) #0 SMP Tue Dec 19 17:42:44 CST 2006
[ 0.000000] [boot]0012 Setup Arch
[ 0.000000] No ramdisk, default root is /dev/sda2
[ 0.000000] EEH: PCI Enhanced I/O Error Handling Enabled
[ 0.000000] PPC64 nvram contains 81920 bytes
[ 0.000000] Zone PFN ranges:
[ 0.000000] DMA 0 -> 262144
[ 0.000000] Normal 262144 -> 262144
[ 0.000000] early_node_map[1] active PFN ranges
[ 0.000000] 0: 0 -> 262144
[ 0.000000] [boot]0015 Setup Done
[ 0.000000] Built 1 zonelists. Total pages: 261888
[ 0.000000] Kernel command line: root=/dev/sda3 console=ttyS0
selinux=0 elevator=cfq kdb=on
[ 0.000000] [boot]0020 XICS Init
[ 0.000000] i8259 legacy interrupt controller initialized
[ 0.000000] [boot]0021 XICS Done
[ 0.000000] PID hash table entries: 4096 (order: 12, 32768 bytes)
cpu 0x0: Vector: 700 (Program Check) at [c0000000007a3980]
pc: c00000000007d574: .debug_mutex_unlock+0x5c/0x118
lr: c000000000468068: .__mutex_unlock_slowpath+0x104/0x198
sp: c0000000007a3c00
msr: 9000000000029032
current = 0xc000000000663690
paca = 0xc000000000663f80
pid = 0, comm = swapper
enter ? for help
[c0000000007a3c80] c000000000468068 .__mutex_unlock_slowpath+0x104/0x198
[c0000000007a3d20] c000000000231da8 .double_unlock_mutex+0x3c/0x58
[c0000000007a3db0] c00000000023b47c .dotest+0x5c/0x370
[c0000000007a3e50] c00000000023bc0c .locking_selftest+0x47c/0x17fc
[c0000000007a3ef0] c0000000005f06ec .start_kernel+0x1e4/0x344
[c0000000007a3f90] c0000000000084c8 .start_here_common+0x54/0x8c
0:mon>
And, exactly the same kernel, on power5:
Looking for displays
found display : /pci@800000020000002/pci@2,2/pci@1/display@0, opening
... done
instantiating rtas at 0x0000000007710000 ... done
0000000000000000 : boot cpu 0000000000000000
0000000000000002 : starting cpu hw idx 0000000000000002... done
copying OF device tree ...
Building dt strings...
Building dt structure...
Device tree strings 0x0000000002580000 -> 0x000000000258141e
Device tree struct 0x0000000002590000 -> 0x00000000025a0000
[ 0.000000] Using pSeries machine description
[ 0.000000] Partition configured for 4 cpus.
[ 0.000000] Starting Linux PPC64 #0 SMP Tue Dec 19 17:42:44 CST 2006
[ 0.000000] -----------------------------------------------------
[ 0.000000] ppc64_pft_size = 0x19
[ 0.000000] physicalMemorySize = 0x72000000
[ 0.000000] ppc64_caches.dcache_line_size = 0x80
[ 0.000000] ppc64_caches.icache_line_size = 0x80
[ 0.000000] htab_address = 0x0000000000000000
[ 0.000000] htab_hash_mask = 0x3ffff
[ 0.000000] -----------------------------------------------------
[ 0.000000] Linux version 2.6.20-rc1-git6linas (root@venn) (gcc
version 4.1.0 (SUSE Linux)) #0 SMP Tue Dec 19 17:42:446[ 0.000000]
[boot]0012 Setup Arch
[ 0.000000] No ramdisk, default root is /dev/sda2
[ 0.000000] EEH: PCI Enhanced I/O Error Handling Enabled
[ 0.000000] PPC64 nvram contains 7168 bytes
[ 0.000000] Zone PFN ranges:
[ 0.000000] DMA 0 -> 29184
[ 0.000000] Normal 29184 -> 29184
[ 0.000000] early_node_map[1] active PFN ranges
[ 0.000000] 0: 0 -> 29184
[ 0.000000] [boot]0015 Setup Done
[ 0.000000] Built 1 zonelists. Total pages: 29156
[ 0.000000] Kernel command line: root=/dev/sda9 console=hvsi0 selinux=0 elevator=cfq rtas_msgs=1
[ 0.000000] [boot]0020 XICS Init
[ 0.000000] [boot]0021 XICS Done
[ 0.000000] PID hash table entries: 4096 (order: 12, 32768 bytes)
[97741.568069] Console: colour dummy device 80x25
[97742.318175] ------------------------
[97742.318182] | Locking API testsuite:
[97742.318189] ----------------------------------------------------------------------------
[97742.318200] | spin |wlock |rlock |mutex | wsem | rsem |
[97742.318211] --------------------------------------------------------------------------
[97742.318222] A-A deadlock:failed|failed| ok |failed|failed|failed|
[97742.318246] A-B-B-A deadlock:failed|failed| ok |failed|failed|failed|
[97742.318271] A-B-B-C-C-A deadlock:failed|failed| ok |failed|failed|failed|
[97742.318297] A-B-C-A-B-C deadlock:failed|failed| ok |failed|failed|failed|
[97742.318323] A-B-B-C-C-D-D-A deadlock:failed|failed| ok |failed|failed|failed|
[97742.318352] A-B-C-D-B-D-D-A deadlock:failed|failed| ok |failed|failed|failed|
[97742.318380] A-B-C-D-B-C-D-A deadlock:failed|failed| ok |failed|failed|failed|
[97742.318408] double unlock: ok | ok |failed|<0>------------[ cut here ]------------
[97742.318440] Kernel BUG at c00000000007d574 [verbose debug info
unavailable]
cpu 0x0: Vector: 700 (Program Check) at [c0000000007a3980]
pc: c00000000007d574: .debug_mutex_unlock+0x5c/0x118
lr: c000000000468068: .__mutex_unlock_slowpath+0x104/0x198
sp: c0000000007a3c00
msr: 8000000000029032
current = 0xc000000000663690
paca = 0xc000000000663f80
pid = 0, comm = swapper
enter ? for help
[c0000000007a3c80] c000000000468068 .__mutex_unlock_slowpath+0x104/0x198
[c0000000007a3d20] c000000000231da8 .double_unlock_mutex+0x3c/0x58
[c0000000007a3db0] c00000000023b47c .dotest+0x5c/0x370
[c0000000007a3e50] c00000000023bc0c .locking_selftest+0x47c/0x17fc
[c0000000007a3ef0] c0000000005f06ec .start_kernel+0x1e4/0x344
[c0000000007a3f90] c0000000000084c8 .start_here_common+0x54/0x8c
0:mon> r
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: Mutex debug lock failure [was Re: Bad gcc-4.1.0 leads to Power4 crashes... and power5 too, actually
2006-12-20 23:46 ` Linas Vepstas
@ 2006-12-21 0:36 ` Anton Blanchard
2006-12-21 1:03 ` Linas Vepstas
0 siblings, 1 reply; 7+ messages in thread
From: Anton Blanchard @ 2006-12-21 0:36 UTC (permalink / raw)
To: Linas Vepstas
Cc: Benjamin Herrenschmidt, Ingo Molnar, linux-kernel, linuxppc-dev
On Wed, Dec 20, 2006 at 05:46:47PM -0600, Linas Vepstas wrote:
> System assert at: file: rtas_io_config.c -- line: 195
> rio_hub_num: 10
> drawer_num: 6
> phb_num: 3
> buid: 7
Looks like a firmware assert. Did you pass in something dodgy to a
config read/write op? Maybe a bad buid?
Anton
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: Mutex debug lock failure [was Re: Bad gcc-4.1.0 leads to Power4 crashes... and power5 too, actually
2006-12-21 0:36 ` Anton Blanchard
@ 2006-12-21 1:03 ` Linas Vepstas
2006-12-21 14:41 ` Ingo Molnar
0 siblings, 1 reply; 7+ messages in thread
From: Linas Vepstas @ 2006-12-21 1:03 UTC (permalink / raw)
To: Anton Blanchard
Cc: Benjamin Herrenschmidt, Ingo Molnar, linux-kernel, linuxppc-dev
On Thu, Dec 21, 2006 at 11:36:59AM +1100, Anton Blanchard wrote:
>
> On Wed, Dec 20, 2006 at 05:46:47PM -0600, Linas Vepstas wrote:
>
> > System assert at: file: rtas_io_config.c -- line: 195
> > rio_hub_num: 10
> > drawer_num: 6
> > phb_num: 3
> > buid: 7
>
> Looks like a firmware assert. Did you pass in something dodgy to a
> config read/write op? Maybe a bad buid?
Same kernel runs fine on power5. Although it does have patches
applied, those very same patches boot fine when applied to a slightly
older kernel (2.6.19-rc4). I haven't been messing with buids or
pci config space (at least not intentionaly).
I'll try again with an unpatched, unmodified kernel.
--linas
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: Mutex debug lock failure [was Re: Bad gcc-4.1.0 leads to Power4 crashes... and power5 too, actually
2006-12-21 1:03 ` Linas Vepstas
@ 2006-12-21 14:41 ` Ingo Molnar
2006-12-21 21:12 ` Linas Vepstas
0 siblings, 1 reply; 7+ messages in thread
From: Ingo Molnar @ 2006-12-21 14:41 UTC (permalink / raw)
To: Linas Vepstas
Cc: Anton Blanchard, Benjamin Herrenschmidt, linux-kernel,
linuxppc-dev, mingo
On Wed, 2006-12-20 at 19:03 -0600, Linas Vepstas wrote:
> Same kernel runs fine on power5. Although it does have patches
> applied, those very same patches boot fine when applied to a slightly
> older kernel (2.6.19-rc4). I haven't been messing with buids or
> pci config space (at least not intentionaly).
>
> I'll try again with an unpatched, unmodified kernel.
there have been a number of fixes to lockdep recently - could you try
the kernel/lockdep.c file from latest -mm, does that fail too?
one possibility would be a chain-hash collision.
Ingo
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: Mutex debug lock failure [was Re: Bad gcc-4.1.0 leads to Power4 crashes... and power5 too, actually
2006-12-21 14:41 ` Ingo Molnar
@ 2006-12-21 21:12 ` Linas Vepstas
0 siblings, 0 replies; 7+ messages in thread
From: Linas Vepstas @ 2006-12-21 21:12 UTC (permalink / raw)
To: Ingo Molnar
Cc: Anton Blanchard, Benjamin Herrenschmidt, linux-kernel,
linuxppc-dev, mingo
On Thu, Dec 21, 2006 at 03:41:39PM +0100, Ingo Molnar wrote:
> On Wed, 2006-12-20 at 19:03 -0600, Linas Vepstas wrote:
> > Same kernel runs fine on power5. Although it does have patches
> > applied, those very same patches boot fine when applied to a slightly
> > older kernel (2.6.19-rc4). I haven't been messing with buids or
> > pci config space (at least not intentionaly).
> >
> > I'll try again with an unpatched, unmodified kernel.
>
> there have been a number of fixes to lockdep recently - could you try
> the kernel/lockdep.c file from latest -mm, does that fail too?
>
> one possibility would be a chain-hash collision.
I see the same problem on linux-2.6.20-rc1-mm1
The patch below fixes this, although I don't understand why
this has become an issue just now:
Index: linux-2.6.20-rc1-mm1/kernel/mutex.c
===================================================================
--- linux-2.6.20-rc1-mm1.orig/kernel/mutex.c 2006-12-19
16:19:34.000000000 -0600
+++ linux-2.6.20-rc1-mm1/kernel/mutex.c 2006-12-21 14:31:33.000000000
-0600
@@ -249,7 +249,7 @@ __mutex_unlock_common_slowpath(atomic_t
wake_up_process(waiter->task);
}
- debug_mutex_clear_owner(lock);
+ // debug_mutex_clear_owner(lock);
spin_unlock_mutex(&lock->wait_lock, flags);
}
It obvious that this is the proximal cause of the failure of
the double_unlock_mutex() mutex self-test. However, both
the double-unlock test, and this clear_owner() call, are
in linux-2.6.19-git7, which doesn't fail this test. So I conclude
that __mutex_unlock_common_slowpath() is never taken in 2.6.19
but is always taken on 2.6.20-rc1 (in particular, is taken
during the double-unlock test).
I don't know why that would be.
It might be wise to add a test to make sure the slowpath
is taken only when it should be taken? Its sort of scary
to think that it might be always taken, and that no one
notices the problem...
I'm gonna be out until after Christmas. -- and so,
Merry Christmas!
--linas
^ permalink raw reply [flat|nested] 7+ messages in thread
end of thread, other threads:[~2006-12-21 21:12 UTC | newest]
Thread overview: 7+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
[not found] <20061220004653.GL5506@austin.ibm.com>
[not found] ` <1166579210.4963.15.camel@otta>
[not found] ` <20061220211931.GB16860@austin.ibm.com>
[not found] ` <1166650134.6673.9.camel@localhost.localdomain>
2006-12-20 23:03 ` Mutex debug lock failure [was Re: Bad gcc-4.1.0 leads to Power4 crashes... and power5 too, actually Linas Vepstas
2006-12-20 23:09 ` Benjamin Herrenschmidt
2006-12-20 23:46 ` Linas Vepstas
2006-12-21 0:36 ` Anton Blanchard
2006-12-21 1:03 ` Linas Vepstas
2006-12-21 14:41 ` Ingo Molnar
2006-12-21 21:12 ` Linas Vepstas
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox