make test under lang/perl5.14 causes panic: blockable sleep lock (sleep mutex) process lock @ /usr/src/sys/ia64/ia64/trap.c:562

[Anton Shterenlikht]

On Fri, Aug 12, 2011 at 03:19:04PM +0100, Anton Shterenlikht wrote:
> On ia64 r221488
> 
> # cd /usr/ports/lang/perl5.14/
> # make test
> 
> isitmychild: rmatrix mismatch between pipe mutex (index 5) and select mtxpool (i
> ndex 447): w_rmatrix[5][447] == 1 but w_rmatrix[447][5] == 4
> KDB: stack backtrace:
> panic: blockable sleep lock (sleep mutex) process lock @ /usr/src/sys/ia64/ia64/
> trap.c:562
> cpuid = 0
> KDB: enter: panic
> [ thread pid 11794 tid 100099 ]
> Stopped at      kdb_enter+0x92: [I2]    addl r14=0xffffffffffe1fe38,gp ;;
> db>
> db> show thread
> Thread 100099 at 0xe000000011d62450:
>  proc (pid 11794): 0xe000000011d1cd38
>  name: initial thread
>  stack: 0xa0000000c8154000-0xa0000000c815bfff
>  flags: 0x10004  pflags: 0
>  state: RUNNING (CPU 0)
>  priority: 132
>  container lock: sched lock 0 (0x9ffc000000a304c0)
> db>
> db> show proc
> Process 11794 (perl) at 0xe000000011d1cd38:
>  state: NORMAL
>  uid: 0  gids: 0, 5
>  parent: pid 2925 at 0xe0000000122bda70
>  ABI: FreeBSD ELF64
>  arguments: ../../t/perl
>  threads: 1
> 100099                   Run     CPU 0                       initial thread
> db>
> db> bt
> Tracing pid 11794 tid 100099 td 0xe000000011d62450
> kdb_enter(0x9ffc000000913e38, 0x9ffc000000913e38, 0x9ffc000000351990, 0x793) at
> kdb_enter+0x92
> panic(0x9ffc00000091cbd8, 0x9ffc000000912538, 0x9ffc000000912518, 0x9ffc00000095
> 3490, 0x232, 0x9ffc000000953490) at panic+0x2e0
> witness_checkorder(0xe000000011d1ce30, 0x9, 0x9ffc000000953490, 0x232, 0x0) at w
> itness_checkorder+0x1b0
> _mtx_lock_flags(0xe000000011d1ce30, 0x0, 0x9ffc000000953490, 0x232, 0x9ffc000000
> 7e1160, 0x716, 0xa0000000c815b208) at _mtx_lock_flags+0x130
> trap(0x14, 0xa0000000c815a400) at trap+0x940
> ivt_Data_TLB() at ivt_Data_TLB+0x1d0
> --- trapframe at 0xa0000000c815a400
> uma_zalloc_arg(0xe0000001ffffbb00, 0x0, 0x1) at uma_zalloc_arg+0x121
> malloc(0x9, 0x9ffc0000009ddd90, 0x1) at malloc+0x290
> unw_alloc(0x10c0, 0x9ffc0000007a1a90) at unw_alloc+0x210
> uwx_init(0x20, 0x9ffc0000007e4590, 0x28a, 0x9ffc000000be51a0) at uwx_init+0x70
> unw_create_from_pcb(0xa0000000c815a700, 0xa0000000c815a7a0, 0x9ffc0000007c47f0)
> at unw_create_from_pcb+0x20
> db_backtrace(0xe000000011d62450, 0xa0000000c815a7a0, 0xffffffffffffffff) at db_b
> acktrace+0x20
> db_trace_self(0x9ffc0000000fef20) at db_trace_self+0x40
> db_trace_self_wrapper(0x9ffc0000003bfea0) at db_trace_self_wrapper+0x70
> kdb_backtrace(0x9ffc000000a04fb8, 0x9ffc0000003eaa50, 0x410, 0x9ffc000000be51a0)
>  at kdb_backtrace+0xc0
> _isitmyx(0xa000000000002280, 0xa00000000000ff80, 0x1, 0x9ffc00000091d388) at _is
> itmyx+0x1c0
> isitmychild(0xa000000000002280, 0xa00000000000ff80, 0x9ffc0000003ee7a0, 0x999, 0
> x8) at isitmychild+0x30
> witness_checkorder(0xe000000011b06890, 0x9, 0x9ffc000000b93100, 0x5fc, 0x0) at w
> itness_checkorder+0x5e0
> _mtx_lock_flags(0xe000000011b06890, 0x0, 0x9ffc00000091d4b8, 0x5fc) at _mtx_lock
> _flags+0x130
> doselwakeup(0xe000000011f082d0, 0x68) at doselwakeup+0x50
> selwakeuppri(0xe000000011f082d0, 0x68, 0x9ffc0000003fa2f0, 0x1734, 0x9ffc0000003
> fa2b0) at selwakeuppri+0x30
> pipe_write(0xe000000011c557e4, 0xa0000000c815b360, 0xe000000011f082d0, 0xe000000
> 011f08360, 0x9ffc00000091d6f0) at pipe_write+0x2750
> dofilewrite(0xe000000011d62450, 0x1, 0xe000000011c557c0, 0xa0000000c815b360, 0xf
> fffffffffffffff, 0x0) at dofilewrite+0x160
> kern_writev(0xe000000011d62450, 0x1, 0xa0000000c815b360) at kern_writev+0x70
> write(0xe000000011d62450, 0xa0000000c815b4e8, 0x9ffc0000003dc9c0, 0x50e) at writ
> e+0xd0
> syscallenter(0xe000000011d62450, 0xa0000000c815b3a0, 0xa0000000c815b3a8) at sysc
> allenter+0x4e0
> syscall(0xa0000000c815b4c8, 0xe000000011d62450, 0x6, 0x9ffc0000007dd880, 0x8, 0x
> 0) at syscall+0x60
> epc_syscall_return() at epc_syscall_return
> db>

just got it again:


panic: _mtx_lock_sleep: recursed on non-recursive mutex process lock @ /usr/src/
sys/ia64/ia64/trap.c:562

cpuid = 0
KDB: enter: panic
[ thread pid 7383 tid 100347 ]
Stopped at      kdb_enter+0x92: [I2]    addl r14=0xffffffffffe1fe38,gp ;;
db>
db> show thread
Thread 100347 at 0xe000000012808000:
 proc (pid 7383): 0xe0000000127f08d0
 name: initial thread
 stack: 0xa0000000c8254000-0xa0000000c825bfff
 flags: 0x4  pflags: 0
 state: RUNNING (CPU 0)
 priority: 186
 container lock: sched lock 0 (0x9ffc000000a304c0)
db>
db> show proc
Process 7383 (perl) at 0xe0000000127f08d0:
 state: NORMAL
 uid: 0  gids: 0, 5
 parent: pid 5803 at 0xe000000011c3fa70
 ABI: FreeBSD ELF64
 arguments: ./perl
 threads: 1
100347                   Run     CPU 0                       initial thread
db>
db> bt
Tracing pid 7383 tid 100347 td 0xe000000012808000
kdb_enter(0x9ffc000000913e38, 0x9ffc000000913e38, 0x9ffc000000351990, 0x793) at
kdb_enter+0x92
panic(0x9ffc000000912470, 0x9ffc000000912518, 0x9ffc000000953490, 0x232) at pani
c+0x2e0
_mtx_lock_sleep(0xe0000000127f09c8, 0xe000000012808000, 0x0, 0x9ffc000000953490,
 0x232) at _mtx_lock_sleep+0x80
_mtx_lock_flags(0xe0000000127f09c8, 0x0, 0x9ffc000000953490, 0x232, 0x9ffc000000
7e1160, 0x716, 0x9ffc000000913040) at _mtx_lock_flags+0x170
trap(0x14, 0xa0000000c825b000) at trap+0x940
ivt_Data_TLB() at ivt_Data_TLB+0x1d0
--- trapframe at 0xa0000000c825b000
crhold() at crhold+0x10
cred_update_thread(0xe000000012808130, 0xe0000000127f0910, 0xe0000000127f09c8, 0
x9ffc000000913040) at cred_update_thread+0x70
syscallenter(0xe000000012808000, 0xa0000000c825b3a0, 0x120ac45d0) at syscallente
r+0x80
syscall(0xa0000000c825b4c8, 0xe000000012808000, 0x0, 0x9ffc0000007dd880, 0x8, 0x
120515a10) at syscall+0x60
epc_syscall_return() at epc_syscall_return
db>


-- 
Anton Shterenlikht
Room 2.6, Queen's Building
Mech Eng Dept
Bristol University
University Walk, Bristol BS8 1TR, UK
Tel: +44 (0)117 331 5944
Fax: +44 (0)117 929 4423