Re: Mutex debug lock failure [was Re: Bad gcc-4.1.0 leads to Power4 crashes... and power5 too, actually

Benjamin Herrenschmidt
2006-12-20T23:10:32Z

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