"sched_lock held too long" panic + trace

[Kris Kennaway]

On Thu, Feb 23, 2006 at 03:47:16PM -0500, Kris Kennaway wrote:
> One of my e4500s has started panicking regularly under load because
> sched_lock was held for > 5 seconds.  Since on sparc64 it always
> deadlocks after this panic instead of entering DDB, I wasn't able to
> track down the cause.  Instead, I changed the panic to first
> DELAY(1000000*PCPU_GET(cpuid)) (so that different CPUs don't overlap
> the printfs) and then kdb_backtrace().
> 
> Doing so I obtained the following trace (still a bit corrupted, but
> hopefully more useful).

> KDB: stack backtrace:
> hardclock_cpu() at hardclock_cpu+0x6c
> tick_hardclock() at tick_hardclock+0xc4
> -- interrupt level=0xe pil=0 %o7=0xc0190a98 --
> _mtx_lock_spin() at _mtx_lock_spin+0xf4
> tlb_page_demap() at tlb_page_demap+0xa0
> pmap_zero_page_idle() at pmap_zero_page_idle+0xdc
> vm_page_zero_idle() at vm_page_zero_idle+0x108
> vm_pagezero() at vm_pagezero+0x4c
> fork_exit() at fork_exit+0x94
> fork_trampoline() at fork_trampoline+0x8

Witness seems to have caught this:

panic: blockable sleep lock (sleep mutex) system map @ vm/vm_map.c:2995
db> wh
Tracing pid 1267 tid 100248 td 0xfffff800612a0540
panic() at panic+0x164
witness_checkorder() at witness_checkorder+0xc8
_mtx_lock_flags() at _mtx_lock_flags+0x80
_vm_map_lock_read() at _vm_map_lock_read+0x3c
vm_map_lookup() at vm_map_lookup+0x1c
vm_fault() at vm_fault+0x68
trap_pfault() at trap_pfault+0x1a8
trap() at trap+0x2b0
-- fast data access mmu miss tar=0xe819c000 %o7=0xc031d204 --
cpu_ipi_selected() at cpu_ipi_selected+0x2c
tlb_page_demap() at tlb_page_demap+0x74
pmap_copy_page() at pmap_copy_page+0x39c
vm_fault() at vm_fault+0xe5c
trap_pfault() at trap_pfault+0x134
trap() at trap+0xa0
-- data access protection tar=0x4065c524 sfar=0x4065d314 sfsr=0x800005 %o7=0x40350c94 --

db> show alllocks
Process 1273 (creat) thread 0xfffff802274dad20 (100604)
exclusive sleep mutex vm object (standard object) r = 0 (0xfffff80223c256a8) locked @ vm/vm_fault.c:686
exclusive sx user map r = 0 (0xfffff802284e2280) locked @ vm/vm_map.c:2995
Process 1272 (thr1) thread 0xfffff80228ab1500 (100353)
exclusive sleep mutex vm object (standard object) r = 0 (0xfffff80227659900) locked @ vm/vm_fault.c:686
exclusive sx user map r = 0 (0xfffff80227cbccd0) locked @ vm/vm_map.c:2995
Process 1271 (swap) thread 0xfffff80226ec3260 (100625)
exclusive sleep mutex vm object (standard object) r = 0 (0xfffff80228772ed8) locked @ vm/vm_fault.c:686
exclusive sx user map r = 0 (0xfffff8005ee15b40) locked @ vm/vm_map.c:2995
Process 1270 (creat) thread 0xfffff80050078fc0 (100605)
exclusive sleep mutex vm object (standard object) r = 0 (0xfffff8021faa3900) locked @ vm/vm_fault.c:789
exclusive sx user map r = 0 (0xfffff802284e2070) locked @ vm/vm_map.c:2995
Process 1267 (thr1) thread 0xfffff800612a0540 (100248)
exclusive sleep mutex pmap r = 0 (0xc0513458) locked @ sparc64/sparc64/pmap.c:1649
exclusive sleep mutex vm object (standard object) r = 0 (0xfffff802279ae0c8) locked @ vm/vm_fault.c:686
exclusive sx user map r = 0 (0xfffff80061410ee0) locked @ vm/vm_map.c:2995
exclusive spin mutex ipi r = 0 (0xc05133c0) locked @ ./machine/smp.h:174
Process 972 (thr1) thread 0xfffff800612a1a40 (100240)
exclusive sleep mutex vm object (standard object) r = 0 (0xfffff802276599c8) locked @ vm/vm_fault.c:686
exclusive sx user map r = 0 (0xfffff8006158e6a0) locked @ vm/vm_map.c:2995
Process 948 (rw) thread 0xfffff80226a02fc0 (100900)
exclusive sleep mutex vm page queue mutex r = 0 (0xc04e4f60) locked @ sparc64/sparc64/pmap.c:937
exclusive sx user map r = 0 (0xfffff8022273c8b0) locked @ vm/vm_map.c:2487
Process 919 (creat) thread 0xfffff8004fef0000 (100350)
exclusive sx user map r = 0 (0xfffff80228064070) locked @ vm/vm_map.c:2995
Process 906 (swap) thread 0xfffff80228aa02a0 (100308)
exclusive sx user map r = 0 (0xfffff80050848ee0) locked @ vm/vm_map.c:2487
Process 35 (syncer) thread 0xfffff802be5a4a80 (100044)
exclusive sleep mutex Giant r = 0 (0xc044b038) locked @ kern/vfs_subr.c:1607
db>

Kris
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 187 bytes
Desc: not available
Url : http://lists.freebsd.org/pipermail/freebsd-sparc64/attachments/20060223/388a0a53/attachment.bin